sneak/routewatch
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
e0a4c8642e
routewatch/log.txt
sneak e0a4c8642e Add context cancellation support to database operations 
- Add context-aware versions of all read operations in the database
- Update handlers to use context from HTTP requests
- Allows database queries to be cancelled when HTTP requests timeout
- Prevents database operations from continuing after client disconnects
2025-07-28 19:27:55 +02:00

1174 lines
222 KiB
Plaintext
Raw Blame History

[Fx] PROVIDE fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] PROVIDE *logger.Logger <= git.eeqj.de/sneak/routewatch/internal/logger.New()
[Fx] PROVIDE *config.Config <= git.eeqj.de/sneak/routewatch/internal/config.New()
[Fx] PROVIDE *metrics.Tracker <= git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] PROVIDE database.Store <= fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
[Fx] PROVIDE *streamer.Streamer <= git.eeqj.de/sneak/routewatch/internal/streamer.New()
[Fx] PROVIDE *server.Server <= git.eeqj.de/sneak/routewatch/internal/server.New()
[Fx] PROVIDE *routewatch.RouteWatch <= git.eeqj.de/sneak/routewatch/internal/routewatch.New()
[Fx] INVOKE git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1()
[Fx] BEFORE RUN provide: go.uber.org/fx.New.func1()
[Fx] RUN provide: go.uber.org/fx.New.func1() in 4.834µs
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/config.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/config.New() in 6.792µs
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/logger.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/logger.New() in 5.041µs
[Fx] BEFORE RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
{"time":"2025-07-28T19:07:04.003748+02:00","level":"INFO","msg":"Opening database","source":"database.go:60","func":"database.New","path":"/Users/user/Library/Application Support/berlin.sneak.app.routewatch/db.sqlite"}
{"time":"2025-07-28T19:07:17.095001+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"PRAGMA wal_checkpoint(TRUNCATE)","duration":3246961625}
{"time":"2025-07-28T19:07:17.096647+02:00","level":"INFO","msg":"Running VACUUM to optimize database (this may take a moment)","source":"database.go:124","func":"database.(*Database).Initialize"}
{"time":"2025-07-28T19:07:33.635837+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"VACUUM","duration":16501666209}
[Fx] RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]]) in 29.642112125s
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New() in 479.791µs
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/streamer.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/streamer.New() in 193.625µs
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/server.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/server.New() in 367.708µs
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/routewatch.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/routewatch.New() in 35.958µs
[Fx] BEFORE RUN provide: go.uber.org/fx.(*App).shutdowner-fm()
[Fx] RUN provide: go.uber.org/fx.(*App).shutdowner-fm() in 164µs
[Fx] HOOK OnStart git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1.1() executing (caller: git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1)
[Fx] HOOK OnStart git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1.1() called by git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1 ran successfully in 2.307875ms
{"time":"2025-07-28T19:07:33.654701+02:00","level":"INFO","msg":"Starting RouteWatch","source":"app.go:64","func":"routewatch.(*RouteWatch).Run"}
[Fx] RUNNING
{"time":"2025-07-28T19:07:33.657587+02:00","level":"INFO","msg":"Using batched database handlers for improved performance","source":"app.go:76","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T19:07:33.662391+02:00","level":"INFO","msg":"Starting HTTP server","source":"server.go:52","func":"server.(*Server).Start","port":"8080"}
2025/07/28 19:07:34 [akrotiri/nRQLu4lSAJ-000001] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3678B in 603.583125ms
2025/07/28 19:07:35 [akrotiri/nRQLu4lSAJ-000002] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3678B in 904.373541ms
2025/07/28 19:07:35 [akrotiri/nRQLu4lSAJ-000004] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3678B in 671.252042ms
2025/07/28 19:07:35 [akrotiri/nRQLu4lSAJ-000003] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3678B in 675.69775ms
2025/07/28 19:07:35 [akrotiri/nRQLu4lSAJ-000006] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3678B in 576.927958ms
2025/07/28 19:07:35 [akrotiri/nRQLu4lSAJ-000005] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3678B in 666.532458ms
{"time":"2025-07-28T19:07:36.003396+02:00","level":"INFO","msg":"Connected to RIS Live stream","source":"streamer.go:347","func":"streamer.(*Streamer).stream"}
2025/07/28 19:07:36 [akrotiri/nRQLu4lSAJ-000007] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3645B in 717.908292ms
2025/07/28 19:07:36 [akrotiri/nRQLu4lSAJ-000008] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3645B in 712.154459ms
{"time":"2025-07-28T19:07:36.672986+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:36.673015+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:07:36 [akrotiri/nRQLu4lSAJ-000009] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3654B in 641.762417ms
{"time":"2025-07-28T19:07:36.864033+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:37 [akrotiri/nRQLu4lSAJ-000011] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3660B in 725.372708ms
2025/07/28 19:07:37 [akrotiri/nRQLu4lSAJ-000012] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3659B in 715.984959ms
2025/07/28 19:07:37 [akrotiri/nRQLu4lSAJ-000010] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3660B in 1.420152834s
{"time":"2025-07-28T19:07:37.659829+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:37 [akrotiri/nRQLu4lSAJ-000014] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59225 - 200 3659B in 784.538792ms
2025/07/28 19:07:37 [akrotiri/nRQLu4lSAJ-000013] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3659B in 788.29225ms
{"time":"2025-07-28T19:07:37.968576+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"196.60.8.170","peer_asn":"327781"}
2025/07/28 19:07:38 [akrotiri/nRQLu4lSAJ-000015] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3663B in 732.397208ms
2025/07/28 19:07:38 [akrotiri/nRQLu4lSAJ-000016] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3663B in 744.506042ms
{"time":"2025-07-28T19:07:38.791129+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"80.81.192.113","peer_asn":"35320"}
2025/07/28 19:07:38 [akrotiri/nRQLu4lSAJ-000017] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3664B in 694.515708ms
2025/07/28 19:07:38 [akrotiri/nRQLu4lSAJ-000018] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3664B in 695.887209ms
{"time":"2025-07-28T19:07:39.107277+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":2434}
{"time":"2025-07-28T19:07:39.107299+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:39.107283+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:39 [akrotiri/nRQLu4lSAJ-000020] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3695B in 641.376541ms
2025/07/28 19:07:39 [akrotiri/nRQLu4lSAJ-000019] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3695B in 674.089541ms
{"time":"2025-07-28T19:07:39.491167+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":383}
{"time":"2025-07-28T19:07:39.491176+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:39.492337+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:39.495165+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:07:39.495174+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:39.503819+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":8}
{"time":"2025-07-28T19:07:39.503828+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:39.50383+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":9561,"unique_prefixes":5394,"success":5394,"duration_ms":2840}
{"time":"2025-07-28T19:07:39.51176+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:39.770906+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":267}
{"time":"2025-07-28T19:07:39.771667+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:39.772244+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:39 [akrotiri/nRQLu4lSAJ-000021] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3750B in 679.232333ms
2025/07/28 19:07:39 [akrotiri/nRQLu4lSAJ-000022] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3750B in 688.925042ms
2025/07/28 19:07:40 [akrotiri/nRQLu4lSAJ-000023] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3750B in 669.686167ms
2025/07/28 19:07:40 [akrotiri/nRQLu4lSAJ-000024] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3750B in 758.231208ms
{"time":"2025-07-28T19:07:40.552627+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:40 [akrotiri/nRQLu4lSAJ-000025] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3753B in 701.078792ms
2025/07/28 19:07:40 [akrotiri/nRQLu4lSAJ-000026] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3753B in 704.207542ms
2025/07/28 19:07:41 [akrotiri/nRQLu4lSAJ-000027] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3754B in 651.290958ms
2025/07/28 19:07:41 [akrotiri/nRQLu4lSAJ-000028] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3754B in 705.348625ms
2025/07/28 19:07:41 [akrotiri/nRQLu4lSAJ-000029] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3754B in 706.697959ms
2025/07/28 19:07:41 [akrotiri/nRQLu4lSAJ-000030] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3754B in 714.660708ms
{"time":"2025-07-28T19:07:42.186146+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":2414}
{"time":"2025-07-28T19:07:42.186168+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:42.186182+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:07:42 [akrotiri/nRQLu4lSAJ-000032] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3755B in 676.637458ms
2025/07/28 19:07:42 [akrotiri/nRQLu4lSAJ-000031] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3755B in 716.843834ms
{"time":"2025-07-28T19:07:42.572063+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:42.572057+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":385}
{"time":"2025-07-28T19:07:42.573153+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:42.575387+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:07:42.575395+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:42.589817+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":14}
{"time":"2025-07-28T19:07:42.589869+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":6536,"success":6536,"duration_ms":3084}
{"time":"2025-07-28T19:07:42.59+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:42.597213+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:42.636158+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":46}
{"time":"2025-07-28T19:07:42.636179+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:42.637205+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:42.840773+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:42 [akrotiri/nRQLu4lSAJ-000033] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3751B in 783.942166ms
2025/07/28 19:07:42 [akrotiri/nRQLu4lSAJ-000034] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3751B in 780.201292ms
2025/07/28 19:07:43 [akrotiri/nRQLu4lSAJ-000035] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3752B in 754.8965ms
2025/07/28 19:07:43 [akrotiri/nRQLu4lSAJ-000036] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3753B in 824.056ms
2025/07/28 19:07:43 [akrotiri/nRQLu4lSAJ-000038] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3753B in 758.55275ms
2025/07/28 19:07:43 [akrotiri/nRQLu4lSAJ-000037] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3753B in 769.920042ms
{"time":"2025-07-28T19:07:44.01219+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1375}
{"time":"2025-07-28T19:07:44.012208+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:44.012194+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:44.30494+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":292}
{"time":"2025-07-28T19:07:44.30497+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:44.307148+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:44.327733+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":22}
{"time":"2025-07-28T19:07:44.327834+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:44.343496+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":15}
{"time":"2025-07-28T19:07:44.343512+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":6936,"success":6936,"duration_ms":1751}
{"time":"2025-07-28T19:07:44.343524+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:44.350607+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:07:44 [akrotiri/nRQLu4lSAJ-000039] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3751B in 712.754583ms
2025/07/28 19:07:44 [akrotiri/nRQLu4lSAJ-000040] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3751B in 710.354792ms
{"time":"2025-07-28T19:07:44.385329+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":41}
{"time":"2025-07-28T19:07:44.385375+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:44.559466+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:44 [akrotiri/nRQLu4lSAJ-000041] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3748B in 702.279541ms
2025/07/28 19:07:44 [akrotiri/nRQLu4lSAJ-000042] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3748B in 701.294542ms
2025/07/28 19:07:45 [akrotiri/nRQLu4lSAJ-000043] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3748B in 695.041792ms
{"time":"2025-07-28T19:07:45.393845+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:45.393863+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1008}
{"time":"2025-07-28T19:07:45.393886+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:45.417963+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":24}
{"time":"2025-07-28T19:07:45.417978+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:45.434464+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":16}
{"time":"2025-07-28T19:07:45.434478+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":5668,"success":5668,"duration_ms":1088}
2025/07/28 19:07:45 [akrotiri/nRQLu4lSAJ-000044] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3741B in 826.800833ms
{"time":"2025-07-28T19:07:45.709986+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:45.710032+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:45 [akrotiri/nRQLu4lSAJ-000046] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3743B in 694.81025ms
2025/07/28 19:07:45 [akrotiri/nRQLu4lSAJ-000045] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3743B in 702.424375ms
{"time":"2025-07-28T19:07:45.932774+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:45.936665+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:45.975087+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:45.975101+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":265}
{"time":"2025-07-28T19:07:46.002255+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":27}
{"time":"2025-07-28T19:07:46.002274+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:46.004553+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":10001041625,"total_messages":40448,"total_bytes":27830819,"total_mb":"26.54","messages_per_sec":"513.85","bits_per_sec":"2839908","mbps":"2.84","total_dropped":0}
{"time":"2025-07-28T19:07:46.004568+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":39967,"dropped":0,"avg_time":211514,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:07:46.004573+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":39967,"dropped":0,"avg_time":133450,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:07:46.004577+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":297,"queue_cap":100000,"processed":39669,"dropped":0,"avg_time":219636,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:07:46.00458+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":39967,"dropped":0,"avg_time":1615,"min_time":0,"max_time":1217875}
2025/07/28 19:07:46 [akrotiri/nRQLu4lSAJ-000048] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3746B in 684.118292ms
{"time":"2025-07-28T19:07:46.429834+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"193.239.118.249","peer_asn":"41255"}
2025/07/28 19:07:46 [akrotiri/nRQLu4lSAJ-000047] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3746B in 788.57475ms
{"time":"2025-07-28T19:07:46.787382+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":785}
{"time":"2025-07-28T19:07:46.787401+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:46.787405+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:07:46 [akrotiri/nRQLu4lSAJ-000050] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3746B in 704.959625ms
2025/07/28 19:07:46 [akrotiri/nRQLu4lSAJ-000049] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3746B in 719.08ms
{"time":"2025-07-28T19:07:46.984448+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":197}
{"time":"2025-07-28T19:07:46.984466+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20085,"unique_prefixes":4980,"success":4980,"duration_ms":1052}
{"time":"2025-07-28T19:07:47.019767+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:47.019782+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:47.04221+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":22}
2025/07/28 19:07:47 [akrotiri/nRQLu4lSAJ-000052] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3743B in 687.238791ms
2025/07/28 19:07:47 [akrotiri/nRQLu4lSAJ-000051] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3743B in 745.021ms
2025/07/28 19:07:47 [akrotiri/nRQLu4lSAJ-000053] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3743B in 696.837417ms
2025/07/28 19:07:47 [akrotiri/nRQLu4lSAJ-000054] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3743B in 703.614834ms
{"time":"2025-07-28T19:07:48.165713+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"195.208.209.174","peer_asn":"25227"}
{"time":"2025-07-28T19:07:48.221125+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:48.221143+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:48.231799+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":10}
{"time":"2025-07-28T19:07:48.25413+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:48.254157+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:48.25997+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:48.326908+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":72}
{"time":"2025-07-28T19:07:48.327021+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:07:48 [akrotiri/nRQLu4lSAJ-000055] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3746B in 693.772708ms
2025/07/28 19:07:48 [akrotiri/nRQLu4lSAJ-000056] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3746B in 702.133083ms
2025/07/28 19:07:48 [akrotiri/nRQLu4lSAJ-000058] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3744B in 697.475208ms
2025/07/28 19:07:48 [akrotiri/nRQLu4lSAJ-000057] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3744B in 710.6995ms
{"time":"2025-07-28T19:07:49.296131+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:49.323427+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:49.323423+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":996}
{"time":"2025-07-28T19:07:49.323474+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:07:49 [akrotiri/nRQLu4lSAJ-000059] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3750B in 688.046209ms
{"time":"2025-07-28T19:07:49.453644+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:49.453659+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":130}
{"time":"2025-07-28T19:07:49.458008+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":4}
{"time":"2025-07-28T19:07:49.458021+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20190,"unique_prefixes":6983,"success":6983,"duration_ms":1205}
2025/07/28 19:07:49 [akrotiri/nRQLu4lSAJ-000060] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3745B in 818.270792ms
2025/07/28 19:07:49 [akrotiri/nRQLu4lSAJ-000061] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3745B in 662.160042ms
2025/07/28 19:07:49 [akrotiri/nRQLu4lSAJ-000062] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3745B in 676.558541ms
{"time":"2025-07-28T19:07:50.06625+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
{"time":"2025-07-28T19:07:50.070162+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
2025/07/28 19:07:50 [akrotiri/nRQLu4lSAJ-000063] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3745B in 677.152625ms
2025/07/28 19:07:50 [akrotiri/nRQLu4lSAJ-000064] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3745B in 669.689125ms
{"time":"2025-07-28T19:07:50.448121+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:50.448139+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:50.454422+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":6}
{"time":"2025-07-28T19:07:50.565058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:50.565073+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:50.566553+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:50.606524+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":41}
{"time":"2025-07-28T19:07:50.606547+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:50.722444+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:7f8:4::73ab:1","peer_asn":"29611"}
2025/07/28 19:07:50 [akrotiri/nRQLu4lSAJ-000065] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3748B in 693.311792ms
2025/07/28 19:07:50 [akrotiri/nRQLu4lSAJ-000066] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3748B in 699.954ms
{"time":"2025-07-28T19:07:51.134236+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"80.81.194.190","peer_asn":"31042"}
2025/07/28 19:07:51 [akrotiri/nRQLu4lSAJ-000068] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3748B in 707.918916ms
2025/07/28 19:07:51 [akrotiri/nRQLu4lSAJ-000067] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3748B in 771.511292ms
{"time":"2025-07-28T19:07:51.461056+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:51.848782+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1242}
{"time":"2025-07-28T19:07:51.848848+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:51.848812+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:51.93417+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":85}
{"time":"2025-07-28T19:07:51.934198+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:51.94368+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":9}
{"time":"2025-07-28T19:07:51.943695+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":8173,"success":8173,"duration_ms":1383}
{"time":"2025-07-28T19:07:52.06137+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T19:07:52.065582+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T19:07:52.632916+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:52.632933+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:52.642619+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":9}
{"time":"2025-07-28T19:07:52.646434+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:52.646482+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:07:52 [akrotiri/nRQLu4lSAJ-000070] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3746B in 870.904125ms
2025/07/28 19:07:52 [akrotiri/nRQLu4lSAJ-000071] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3746B in 871.853125ms
2025/07/28 19:07:52 [akrotiri/nRQLu4lSAJ-000072] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3746B in 890.421666ms
{"time":"2025-07-28T19:07:52.769576+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:52 [akrotiri/nRQLu4lSAJ-000069] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3751B in 1.017418291s
{"time":"2025-07-28T19:07:52.958053+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"80.81.194.92","peer_asn":"57111"}
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000073] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59225 - 200 3750B in 845.957791ms
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000074] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59361 - 200 3750B in 843.555208ms
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000075] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3750B in 805.870541ms
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000076] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3750B in 825.081125ms
{"time":"2025-07-28T19:07:53.61985+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:53.870881+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1224}
{"time":"2025-07-28T19:07:53.870901+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:53.871004+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000077] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3755B in 763.138375ms
2025/07/28 19:07:53 [akrotiri/nRQLu4lSAJ-000078] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3755B in 761.375958ms
{"time":"2025-07-28T19:07:53.974506+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":103}
{"time":"2025-07-28T19:07:53.974544+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:53.975705+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:53.97694+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":2}
{"time":"2025-07-28T19:07:53.977005+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:53.992346+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":15}
{"time":"2025-07-28T19:07:53.992359+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:53.992363+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20060,"unique_prefixes":10445,"success":10445,"duration_ms":1363}
{"time":"2025-07-28T19:07:54.003621+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:54.049992+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:54.050057+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":57}
{"time":"2025-07-28T19:07:54.05159+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:54 [akrotiri/nRQLu4lSAJ-000079] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3748B in 782.620916ms
2025/07/28 19:07:54 [akrotiri/nRQLu4lSAJ-000080] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3748B in 775.60675ms
{"time":"2025-07-28T19:07:55.014494+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000081] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3750B in 828.106958ms
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000082] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3753B in 831.940291ms
{"time":"2025-07-28T19:07:55.234058+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1184}
{"time":"2025-07-28T19:07:55.234075+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:55.234059+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:55.383518+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":149}
{"time":"2025-07-28T19:07:55.38354+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:55.385772+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:55.388237+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":4}
{"time":"2025-07-28T19:07:55.388261+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:55.392534+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":4}
{"time":"2025-07-28T19:07:55.392548+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20007,"unique_prefixes":10489,"success":10489,"duration_ms":1398}
{"time":"2025-07-28T19:07:55.392585+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:55.404466+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:55.478219+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":85}
{"time":"2025-07-28T19:07:55.47825+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:55.48057+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000084] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3750B in 810.51475ms
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000083] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3750B in 825.17325ms
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000086] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3750B in 758.836375ms
2025/07/28 19:07:55 [akrotiri/nRQLu4lSAJ-000085] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3750B in 766.820959ms
{"time":"2025-07-28T19:07:56.004642+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":20001042667,"total_messages":96768,"total_bytes":71476257,"total_mb":"68.17","messages_per_sec":"1184.63","bits_per_sec":"6946267","mbps":"6.95","total_dropped":0}
{"time":"2025-07-28T19:07:56.004665+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":5972,"queue_cap":100000,"processed":89786,"dropped":0,"avg_time":132996,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:07:56.00467+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":95759,"dropped":0,"avg_time":63838,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:07:56.004675+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":7170,"queue_cap":100000,"processed":88588,"dropped":0,"avg_time":170700,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:07:56.004678+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":95759,"dropped":0,"avg_time":1799,"min_time":0,"max_time":3326042}
2025/07/28 19:07:56 [akrotiri/nRQLu4lSAJ-000087] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3751B in 735.267334ms
{"time":"2025-07-28T19:07:56.456094+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:56 [akrotiri/nRQLu4lSAJ-000088] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3752B in 760.225458ms
{"time":"2025-07-28T19:07:56.563199+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1084}
{"time":"2025-07-28T19:07:56.563219+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:56.563236+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:56.67658+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":113}
{"time":"2025-07-28T19:07:56.676616+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:56.678673+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:56.679956+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:07:56.680035+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:56.68251+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":2}
{"time":"2025-07-28T19:07:56.682522+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":11375,"success":11375,"duration_ms":1288}
{"time":"2025-07-28T19:07:56.682552+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:56.697985+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:56.820378+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":137}
{"time":"2025-07-28T19:07:56.820402+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:56.82158+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:56 [akrotiri/nRQLu4lSAJ-000089] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3752B in 786.163708ms
2025/07/28 19:07:57 [akrotiri/nRQLu4lSAJ-000090] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3752B in 808.440625ms
{"time":"2025-07-28T19:07:57.325497+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"80.249.210.89","peer_asn":"31042"}
{"time":"2025-07-28T19:07:57.416999+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:57 [akrotiri/nRQLu4lSAJ-000091] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3759B in 781.648208ms
2025/07/28 19:07:57 [akrotiri/nRQLu4lSAJ-000092] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3759B in 777.83225ms
2025/07/28 19:07:58 [akrotiri/nRQLu4lSAJ-000093] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3759B in 731.82675ms
2025/07/28 19:07:58 [akrotiri/nRQLu4lSAJ-000094] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3759B in 740.918209ms
{"time":"2025-07-28T19:07:58.032601+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1212}
{"time":"2025-07-28T19:07:58.032625+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:58.032608+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:58.094801+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":62}
{"time":"2025-07-28T19:07:58.094816+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:58.096021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:58.096984+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":2}
{"time":"2025-07-28T19:07:58.096997+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:58.098353+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":1}
{"time":"2025-07-28T19:07:58.098363+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20002,"unique_prefixes":12115,"success":12115,"duration_ms":1413}
{"time":"2025-07-28T19:07:58.098388+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:58.113012+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:58.199584+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:58.19958+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":101}
{"time":"2025-07-28T19:07:58.200716+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:58.472772+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:07:58 [akrotiri/nRQLu4lSAJ-000095] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3760B in 763.777959ms
2025/07/28 19:07:58 [akrotiri/nRQLu4lSAJ-000096] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3761B in 774.523041ms
{"time":"2025-07-28T19:07:58.635195+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"2602:fa91:0:cccc::20","peer_asn":"53427"}
2025/07/28 19:07:58 [akrotiri/nRQLu4lSAJ-000097] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3761B in 775.922417ms
2025/07/28 19:07:59 [akrotiri/nRQLu4lSAJ-000098] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3763B in 798.730542ms
{"time":"2025-07-28T19:07:59.277503+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:59.277472+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1077}
{"time":"2025-07-28T19:07:59.277617+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:59.43262+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":155}
{"time":"2025-07-28T19:07:59.433803+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:59.43381+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:07:59 [akrotiri/nRQLu4lSAJ-000099] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3763B in 746.758958ms
2025/07/28 19:07:59 [akrotiri/nRQLu4lSAJ-000100] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3763B in 746.649708ms
{"time":"2025-07-28T19:07:59.515959+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:59.515961+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":82}
{"time":"2025-07-28T19:07:59.517117+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:59.517871+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:07:59.51788+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":1}
{"time":"2025-07-28T19:07:59.519218+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:59.519238+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":1}
{"time":"2025-07-28T19:07:59.51926+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20036,"unique_prefixes":10966,"success":10966,"duration_ms":1419}
{"time":"2025-07-28T19:07:59.519737+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:59.529842+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:07:59.567245+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":48}
{"time":"2025-07-28T19:07:59.56728+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:07:59.5684+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:07:59.569388+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":2}
{"time":"2025-07-28T19:07:59.569429+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:07:59 [akrotiri/nRQLu4lSAJ-000101] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3761B in 764.993875ms
2025/07/28 19:08:00 [akrotiri/nRQLu4lSAJ-000102] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3761B in 774.816541ms
{"time":"2025-07-28T19:08:00.064229+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:00 [akrotiri/nRQLu4lSAJ-000103] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3765B in 748.079ms
2025/07/28 19:08:00 [akrotiri/nRQLu4lSAJ-000104] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3765B in 783.1225ms
{"time":"2025-07-28T19:08:00.620066+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1050}
{"time":"2025-07-28T19:08:00.620079+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:00.620085+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:00.704707+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":84}
{"time":"2025-07-28T19:08:00.704797+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:00.706413+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:00.706636+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":1}
{"time":"2025-07-28T19:08:00.706643+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:00.709913+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":3}
{"time":"2025-07-28T19:08:00.70992+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:00.709924+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20003,"unique_prefixes":10446,"success":10446,"duration_ms":1188}
{"time":"2025-07-28T19:08:00.720894+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:00.79123+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":81}
{"time":"2025-07-28T19:08:00.791254+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:00.792429+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:00 [akrotiri/nRQLu4lSAJ-000106] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3761B in 739.773042ms
2025/07/28 19:08:00 [akrotiri/nRQLu4lSAJ-000105] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3761B in 753.927583ms
2025/07/28 19:08:01 [akrotiri/nRQLu4lSAJ-000107] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3761B in 751.062375ms
2025/07/28 19:08:01 [akrotiri/nRQLu4lSAJ-000108] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3761B in 762.420375ms
{"time":"2025-07-28T19:08:01.565814+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:7f8::7942:0:1","peer_asn":"31042"}
{"time":"2025-07-28T19:08:01.587985+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:01 [akrotiri/nRQLu4lSAJ-000110] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3764B in 733.316541ms
2025/07/28 19:08:02 [akrotiri/nRQLu4lSAJ-000109] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3764B in 776.968625ms
{"time":"2025-07-28T19:08:02.073141+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1281}
{"time":"2025-07-28T19:08:02.073146+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:02.073185+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:02.125268+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":52}
{"time":"2025-07-28T19:08:02.125279+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:02.126945+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:02.128212+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":2}
{"time":"2025-07-28T19:08:02.128249+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:02.132224+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":3}
{"time":"2025-07-28T19:08:02.132232+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:02.132236+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20178,"unique_prefixes":12081,"success":12081,"duration_ms":1420}
{"time":"2025-07-28T19:08:02.146181+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:02.24666+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":114}
{"time":"2025-07-28T19:08:02.246673+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:02.247964+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:02 [akrotiri/nRQLu4lSAJ-000111] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3761B in 744.355667ms
2025/07/28 19:08:02 [akrotiri/nRQLu4lSAJ-000112] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3761B in 773.2495ms
2025/07/28 19:08:03 [akrotiri/nRQLu4lSAJ-000114] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3761B in 750.066916ms
2025/07/28 19:08:03 [akrotiri/nRQLu4lSAJ-000113] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3761B in 752.982917ms
2025/07/28 19:08:03 [akrotiri/nRQLu4lSAJ-000116] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3761B in 768.463791ms
2025/07/28 19:08:03 [akrotiri/nRQLu4lSAJ-000115] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3761B in 770.904166ms
{"time":"2025-07-28T19:08:03.641517+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1394}
{"time":"2025-07-28T19:08:03.641526+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:03.641538+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:03.753251+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":111}
{"time":"2025-07-28T19:08:03.753291+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:03.75591+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:03.759854+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":6}
{"time":"2025-07-28T19:08:03.759866+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":14843,"success":14843,"duration_ms":1625}
{"time":"2025-07-28T19:08:03.759886+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:03.772878+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:03.863427+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":103}
{"time":"2025-07-28T19:08:03.863431+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:03.865955+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:03 [akrotiri/nRQLu4lSAJ-000117] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3762B in 741.542208ms
2025/07/28 19:08:04 [akrotiri/nRQLu4lSAJ-000118] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3761B in 751.191208ms
{"time":"2025-07-28T19:08:04.092732+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"102.67.56.1","peer_asn":"328474"}
{"time":"2025-07-28T19:08:04.259315+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:04.385529+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
{"time":"2025-07-28T19:08:04.385629+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
2025/07/28 19:08:04 [akrotiri/nRQLu4lSAJ-000120] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3764B in 772.839292ms
2025/07/28 19:08:04 [akrotiri/nRQLu4lSAJ-000119] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3764B in 782.157667ms
{"time":"2025-07-28T19:08:04.954011+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:12f8::221:238","peer_asn":"262317"}
2025/07/28 19:08:05 [akrotiri/nRQLu4lSAJ-000122] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3763B in 783.544667ms
2025/07/28 19:08:05 [akrotiri/nRQLu4lSAJ-000121] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3763B in 789.895292ms
{"time":"2025-07-28T19:08:05.052625+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1189}
{"time":"2025-07-28T19:08:05.052643+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:05.052655+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:05.105556+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":52}
{"time":"2025-07-28T19:08:05.105565+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:05.106782+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:05.108567+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:08:05.108599+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:05.112153+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":3}
{"time":"2025-07-28T19:08:05.11217+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20078,"unique_prefixes":12394,"success":12394,"duration_ms":1350}
{"time":"2025-07-28T19:08:05.112171+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:05.127667+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:05.206908+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":94}
{"time":"2025-07-28T19:08:05.206916+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:05.208013+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:05 [akrotiri/nRQLu4lSAJ-000123] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3758B in 826.184708ms
2025/07/28 19:08:05 [akrotiri/nRQLu4lSAJ-000124] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3758B in 839.739833ms
{"time":"2025-07-28T19:08:05.816151+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:06.004191+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":30000484167,"total_messages":172032,"total_bytes":126005632,"total_mb":"120.17","messages_per_sec":"2165.68","bits_per_sec":"12786101","mbps":"12.79","total_dropped":0}
{"time":"2025-07-28T19:08:06.004226+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":10894,"queue_cap":100000,"processed":159687,"dropped":0,"avg_time":135667,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:06.004237+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":1441,"queue_cap":100000,"processed":169140,"dropped":0,"avg_time":60095,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:06.004315+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":19350,"queue_cap":100000,"processed":151231,"dropped":0,"avg_time":164230,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:06.004354+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":170582,"dropped":0,"avg_time":1814,"min_time":0,"max_time":3326042}
2025/07/28 19:08:06 [akrotiri/nRQLu4lSAJ-000125] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 200 3762B in 861.26525ms
2025/07/28 19:08:06 [akrotiri/nRQLu4lSAJ-000126] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3762B in 878.993083ms
2025/07/28 19:08:06 [akrotiri/nRQLu4lSAJ-000127] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 200 3763B in 826.930041ms
2025/07/28 19:08:06 [akrotiri/nRQLu4lSAJ-000128] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3763B in 838.380708ms
{"time":"2025-07-28T19:08:07.102186+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1895}
{"time":"2025-07-28T19:08:07.102203+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:07.102207+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:07.111804+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:07.111819+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":9}
{"time":"2025-07-28T19:08:07.111839+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20010,"unique_prefixes":12491,"success":12491,"duration_ms":1998}
{"time":"2025-07-28T19:08:07.135738+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:07.144036+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
{"time":"2025-07-28T19:08:07.144057+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:07 [akrotiri/nRQLu4lSAJ-000131] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59151 - 408 151B in 379.261416ms
2025/07/28 19:08:07 [akrotiri/nRQLu4lSAJ-000129] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59154 - 408 151B in 406.081625ms
{"time":"2025-07-28T19:08:07.155384+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:07.155547+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":43}
{"time":"2025-07-28T19:08:07.158127+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:07.15936+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:08:07.159375+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:07 [akrotiri/nRQLu4lSAJ-000130] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3760B in 957.286084ms
2025/07/28 19:08:07 [akrotiri/nRQLu4lSAJ-000132] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3760B in 939.063083ms
{"time":"2025-07-28T19:08:07.71021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:08 [akrotiri/nRQLu4lSAJ-000134] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59361 - 200 3763B in 894.611167ms
2025/07/28 19:08:08 [akrotiri/nRQLu4lSAJ-000135] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 200 3763B in 888.741ms
{"time":"2025-07-28T19:08:08.16524+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"103.200.113.1","peer_asn":"131477"}
2025/07/28 19:08:08 [akrotiri/nRQLu4lSAJ-000136] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3763B in 854.105834ms
2025/07/28 19:08:08 [akrotiri/nRQLu4lSAJ-000137] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3763B in 855.303625ms
{"time":"2025-07-28T19:08:08.710087+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:08.710087+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1550}
{"time":"2025-07-28T19:08:08.710167+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:08.73078+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:08.730844+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":20}
{"time":"2025-07-28T19:08:08.732323+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:08.735035+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:08.735132+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":4}
{"time":"2025-07-28T19:08:08.749723+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:08.749739+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":14}
{"time":"2025-07-28T19:08:08.749769+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":10761,"success":10761,"duration_ms":1636}
{"time":"2025-07-28T19:08:08.762742+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:08.791185+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":41}
{"time":"2025-07-28T19:08:08.791219+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:08.792569+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:09 [akrotiri/nRQLu4lSAJ-000138] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59361 - 200 3760B in 903.582542ms
2025/07/28 19:08:09 [akrotiri/nRQLu4lSAJ-000139] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 200 3760B in 893.859041ms
2025/07/28 19:08:09 [akrotiri/nRQLu4lSAJ-000133] "GET http://127.0.0.1:8080/prefixlength/22 HTTP/1.1" from 127.0.0.1:59225 - 408 135B in 2.000398917s
2025/07/28 19:08:09 [akrotiri/nRQLu4lSAJ-000141] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3760B in 1.10750725s
2025/07/28 19:08:09 [akrotiri/nRQLu4lSAJ-000140] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3760B in 1.121125584s
{"time":"2025-07-28T19:08:10.062221+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:10.102263+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:10.102263+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1311}
{"time":"2025-07-28T19:08:10.102294+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:10.135009+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":32}
{"time":"2025-07-28T19:08:10.135276+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:10.137338+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:10.141868+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":6}
{"time":"2025-07-28T19:08:10.142041+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:10.153681+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:10.153838+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":11}
{"time":"2025-07-28T19:08:10.153852+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":8531,"success":8531,"duration_ms":1401}
{"time":"2025-07-28T19:08:10.161405+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:10.204999+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":51}
{"time":"2025-07-28T19:08:10.205075+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:10.207641+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:10 [akrotiri/nRQLu4lSAJ-000143] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 200 3760B in 1.146915958s
2025/07/28 19:08:10 [akrotiri/nRQLu4lSAJ-000144] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59376 - 200 3760B in 1.159083416s
{"time":"2025-07-28T19:08:10.802585+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:10 [akrotiri/nRQLu4lSAJ-000145] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59377 - 408 17B in 1.001297458s
{"time":"2025-07-28T19:08:10.837049+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"2400:c3e0::2","peer_asn":"142271"}
{"time":"2025-07-28T19:08:10.91727+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":712}
{"time":"2025-07-28T19:08:10.917293+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:10.917298+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:10.933631+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:10.934167+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":16}
{"time":"2025-07-28T19:08:10.934218+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":2865,"success":2865,"duration_ms":777}
{"time":"2025-07-28T19:08:10.94409+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:10.980883+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":47}
{"time":"2025-07-28T19:08:10.981341+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:10.983384+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000146] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3759B in 1.203097334s
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000142] "GET http://127.0.0.1:8080/prefixlength/22 HTTP/1.1" from 127.0.0.1:59361 - 408 135B in 2.000990667s
{"time":"2025-07-28T19:08:11.286307+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"198.32.160.113","peer_asn":"15547"}
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000147] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3760B in 1.233922791s
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000148] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 200 3760B in 1.187058833s
{"time":"2025-07-28T19:08:11.779192+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000149] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59376 - 408 17B in 1.0028745s
{"time":"2025-07-28T19:08:11.804012+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:11 [akrotiri/nRQLu4lSAJ-000150] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59379 - 408 17B in 1.000656708s
2025/07/28 19:08:12 [akrotiri/nRQLu4lSAJ-000151] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 200 3760B in 1.314775292s
{"time":"2025-07-28T19:08:12.521089+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1539}
{"time":"2025-07-28T19:08:12.521124+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:12.521133+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:12.556054+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:12.556099+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":34}
{"time":"2025-07-28T19:08:12.556128+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":3913,"success":3913,"duration_ms":1619}
{"time":"2025-07-28T19:08:12.617882+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":61}
{"time":"2025-07-28T19:08:12.620312+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:12.620326+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:12.733693+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":111}
{"time":"2025-07-28T19:08:12.73616+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:12.736186+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:12.775116+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":38}
2025/07/28 19:08:12 [akrotiri/nRQLu4lSAJ-000153] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 200 3753B in 1.267609459s
{"time":"2025-07-28T19:08:12.785153+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:12 [akrotiri/nRQLu4lSAJ-000155] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59381 - 408 17B in 1.003883s
{"time":"2025-07-28T19:08:12.806171+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:12 [akrotiri/nRQLu4lSAJ-000156] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59382 - 408 17B in 1.000950167s
{"time":"2025-07-28T19:08:12.849975+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:12.850003+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:12.880337+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":30}
2025/07/28 19:08:12 [akrotiri/nRQLu4lSAJ-000154] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 200 3753B in 1.345688208s
{"time":"2025-07-28T19:08:13.138476+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:13.138503+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000152] "GET http://127.0.0.1:8080/prefixlength/22 HTTP/1.1" from 127.0.0.1:59380 - 408 135B in 2.002604958s
{"time":"2025-07-28T19:08:13.410969+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000157] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59153 - 408 17B in 1.001096958s
{"time":"2025-07-28T19:08:13.646076+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":507}
{"time":"2025-07-28T19:08:13.646095+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:13.6461+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:13.652136+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":5}
{"time":"2025-07-28T19:08:13.652197+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":4767,"success":4767,"duration_ms":520}
{"time":"2025-07-28T19:08:13.785883+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000158] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59150 - 408 17B in 1.006791959s
{"time":"2025-07-28T19:08:13.787357+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000159] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59384 - 408 17B in 1.001558666s
{"time":"2025-07-28T19:08:13.807074+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000160] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59385 - 408 17B in 1.000131625s
{"time":"2025-07-28T19:08:13.957189+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:13 [akrotiri/nRQLu4lSAJ-000161] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59374 - 408 17B in 1.001823167s
{"time":"2025-07-28T19:08:14.183508+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:14 [akrotiri/nRQLu4lSAJ-000162] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59386 - 408 17B in 1.000910667s
{"time":"2025-07-28T19:08:14.261084+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:14.261113+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:14.323682+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":62}
{"time":"2025-07-28T19:08:14.506607+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:b18:10::3","peer_asn":"47787"}
{"time":"2025-07-28T19:08:14.667334+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:14.667368+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:14.790016+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:14 [akrotiri/nRQLu4lSAJ-000164] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59388 - 408 17B in 1.000692s
{"time":"2025-07-28T19:08:14.799135+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:14 [akrotiri/nRQLu4lSAJ-000165] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59389 - 408 17B in 1.008588417s
{"time":"2025-07-28T19:08:14.961095+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:14 [akrotiri/nRQLu4lSAJ-000167] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59391 - 408 17B in 1.001378458s
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000166] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59390 - 200 3755B in 1.288205208s
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000163] "GET http://127.0.0.1:8080/prefixlength/22 HTTP/1.1" from 127.0.0.1:59387 - 408 135B in 2.001762166s
{"time":"2025-07-28T19:08:15.186082+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000168] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59392 - 408 17B in 1.000421291s
{"time":"2025-07-28T19:08:15.291864+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes","duration":56013625}
{"time":"2025-07-28T19:08:15.440781+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":773}
{"time":"2025-07-28T19:08:15.4408+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:15.440804+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:15.442674+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":1}
{"time":"2025-07-28T19:08:15.442687+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":8234,"unique_prefixes":1663,"success":1663,"duration_ms":779}
{"time":"2025-07-28T19:08:15.660325+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:15.66036+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:15.792499+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000169] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59394 - 408 17B in 1.001657917s
{"time":"2025-07-28T19:08:15.801348+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000170] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59395 - 408 17B in 1.001492791s
{"time":"2025-07-28T19:08:15.839252+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:15.908511+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":248}
{"time":"2025-07-28T19:08:15.912469+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:15.967145+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:15 [akrotiri/nRQLu4lSAJ-000171] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59396 - 408 17B in 1.003547167s
{"time":"2025-07-28T19:08:16.008638+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":40004628500,"total_messages":210432,"total_bytes":152371437,"total_mb":"145.31","messages_per_sec":"2523.63","bits_per_sec":"14628534","mbps":"14.63","total_dropped":0}
{"time":"2025-07-28T19:08:16.017094+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":204,"queue_cap":100000,"processed":208259,"dropped":0,"avg_time":140660,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:16.01711+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":208464,"dropped":0,"avg_time":61546,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:16.017118+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":208464,"dropped":0,"avg_time":159871,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:16.017126+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":208464,"dropped":0,"avg_time":1898,"min_time":0,"max_time":10314750}
{"time":"2025-07-28T19:08:16.044008+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":131}
{"time":"2025-07-28T19:08:16.109469+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:16 [akrotiri/nRQLu4lSAJ-000172] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59390 - 408 17B in 1.00463425s
{"time":"2025-07-28T19:08:16.187409+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:16 [akrotiri/nRQLu4lSAJ-000173] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59397 - 408 17B in 1.001187916s
{"time":"2025-07-28T19:08:16.66975+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:16.669766+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:16.799905+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:16 [akrotiri/nRQLu4lSAJ-000175] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59399 - 408 17B in 1.006673667s
{"time":"2025-07-28T19:08:16.801779+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:de8:4::1:8403:1","peer_asn":"18403"}
{"time":"2025-07-28T19:08:16.802145+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:16 [akrotiri/nRQLu4lSAJ-000176] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59400 - 408 17B in 1.000122541s
{"time":"2025-07-28T19:08:16.968794+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:16 [akrotiri/nRQLu4lSAJ-000177] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59401 - 408 17B in 1.000725166s
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000183] "GET http://127.0.0.1:8080/prefixlength/128 HTTP/1.1" from 127.0.0.1:59408 - 200 7442B in 1.795959ms
{"time":"2025-07-28T19:08:17.118767+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000178] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59402 - 408 17B in 1.008219917s
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000174] "GET http://127.0.0.1:8080/prefixlength/22 HTTP/1.1" from 127.0.0.1:59398 - 200 191902B in 1.998639042s
{"time":"2025-07-28T19:08:17.1904+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000179] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59403 - 408 17B in 1.002409125s
{"time":"2025-07-28T19:08:17.272694+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:17.802801+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000180] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59405 - 408 17B in 1.000817958s
{"time":"2025-07-28T19:08:17.803362+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:43f8:6d0::60","peer_asn":"37468"}
{"time":"2025-07-28T19:08:17.806676+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000181] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59406 - 408 17B in 1.004242083s
{"time":"2025-07-28T19:08:17.976576+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:17 [akrotiri/nRQLu4lSAJ-000182] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59407 - 408 17B in 1.003798167s
{"time":"2025-07-28T19:08:17.998312+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM peerings","duration":66096000}
{"time":"2025-07-28T19:08:18.124502+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000184] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59408 - 408 17B in 1.004432s
{"time":"2025-07-28T19:08:18.178122+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes WHERE ip_version = ?","duration":131551500}
{"time":"2025-07-28T19:08:18.186574+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000185] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59398 - 408 17B in 1.000868167s
{"time":"2025-07-28T19:08:18.191922+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000186] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59409 - 408 17B in 1.000417083s
{"time":"2025-07-28T19:08:18.259671+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM bgp_peers","duration":64531292}
{"time":"2025-07-28T19:08:18.259997+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes","duration":65359084}
{"time":"2025-07-28T19:08:18.278504+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM asns","duration":85992417}
{"time":"2025-07-28T19:08:18.304314+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:18.32996+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1660}
{"time":"2025-07-28T19:08:18.329976+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:18.329981+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:18.330027+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes WHERE ip_version = ?","duration":70415625}
{"time":"2025-07-28T19:08:18.347879+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:18.348036+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":17}
{"time":"2025-07-28T19:08:18.348091+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":13654,"unique_prefixes":3860,"success":3860,"duration_ms":1684}
{"time":"2025-07-28T19:08:18.385798+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:18.386296+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":37}
{"time":"2025-07-28T19:08:18.40841+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:18.442814+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:18.485114+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":99}
{"time":"2025-07-28T19:08:18.48537+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:18.485416+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes WHERE ip_version = ?","duration":125381833}
{"time":"2025-07-28T19:08:18.575325+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":89}
{"time":"2025-07-28T19:08:18.575578+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:18.805812+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000187] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59410 - 408 17B in 1.00254275s
{"time":"2025-07-28T19:08:18.808577+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000188] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59411 - 408 17B in 1.024969375s
{"time":"2025-07-28T19:08:18.979246+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:18 [akrotiri/nRQLu4lSAJ-000189] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59412 - 408 17B in 1.001201917s
{"time":"2025-07-28T19:08:19.127074+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM prefixes","duration":143170791}
{"time":"2025-07-28T19:08:19.130041+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:19 [akrotiri/nRQLu4lSAJ-000190] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59413 - 408 17B in 1.004298s
{"time":"2025-07-28T19:08:19.19263+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
{"time":"2025-07-28T19:08:19.200033+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:19 [akrotiri/nRQLu4lSAJ-000191] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59414 - 408 17B in 1.011819916s
2025/07/28 19:08:19 [akrotiri/nRQLu4lSAJ-000192] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59415 - 408 17B in 1.007628375s
{"time":"2025-07-28T19:08:19.276227+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM bgp_peers","duration":89706875}
{"time":"2025-07-28T19:08:19.286193+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM asns","duration":84675625}
{"time":"2025-07-28T19:08:19.808954+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:19 [akrotiri/nRQLu4lSAJ-000193] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59417 - 408 17B in 1.001136459s
{"time":"2025-07-28T19:08:19.841998+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:19 [akrotiri/nRQLu4lSAJ-000194] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59418 - 408 17B in 1.007844417s
{"time":"2025-07-28T19:08:20.005451+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000195] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59419 - 408 17B in 1.024671542s
{"time":"2025-07-28T19:08:20.116723+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:20.132483+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000196] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59420 - 408 17B in 1.00057575s
{"time":"2025-07-28T19:08:20.202532+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000197] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59421 - 408 17B in 1.001289417s
{"time":"2025-07-28T19:08:20.202887+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000198] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59422 - 408 17B in 1.001543166s
{"time":"2025-07-28T19:08:20.543539+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"SELECT COUNT(*) FROM peerings","duration":187139125}
{"time":"2025-07-28T19:08:20.70497+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":2129}
{"time":"2025-07-28T19:08:20.705+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:20.705008+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:20.711695+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:20.71258+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":6}
{"time":"2025-07-28T19:08:20.712604+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20003,"unique_prefixes":9835,"success":9835,"duration_ms":2282}
{"time":"2025-07-28T19:08:20.7633+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":51}
{"time":"2025-07-28T19:08:20.811179+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000199] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59423 - 408 17B in 1.000767708s
{"time":"2025-07-28T19:08:20.843804+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:20 [akrotiri/nRQLu4lSAJ-000200] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59424 - 408 17B in 1.001282125s
{"time":"2025-07-28T19:08:21.009173+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000201] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59425 - 408 17B in 1.001428625s
{"time":"2025-07-28T19:08:21.135173+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000202] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59426 - 408 17B in 1.002054125s
{"time":"2025-07-28T19:08:21.204549+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:250","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000204] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59427 - 408 17B in 1.001135084s
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000203] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3754B in 1.13904825s
{"time":"2025-07-28T19:08:21.641501+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:21.641516+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:21.717351+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":75}
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000205] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 1.018510834s
2025/07/28 19:08:21 [akrotiri/nRQLu4lSAJ-000206] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 1.020566333s
{"time":"2025-07-28T19:08:22.048299+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:22.048315+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:22.077782+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:22.11331+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":64}
{"time":"2025-07-28T19:08:22.113265+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000207] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 1.1265015s
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000208] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3756B in 1.06053575s
{"time":"2025-07-28T19:08:22.320431+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"196.60.8.60","peer_asn":"37468"}
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000209] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3757B in 1.152573584s
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000210] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3760B in 1.135201958s
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000212] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3757B in 1.125838625s
2025/07/28 19:08:22 [akrotiri/nRQLu4lSAJ-000211] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3757B in 1.169336541s
{"time":"2025-07-28T19:08:23.122404+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"193.107.13.3","peer_asn":"47787"}
2025/07/28 19:08:23 [akrotiri/nRQLu4lSAJ-000213] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3757B in 1.109921584s
2025/07/28 19:08:23 [akrotiri/nRQLu4lSAJ-000214] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3757B in 1.117077583s
{"time":"2025-07-28T19:08:23.374575+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:23.385104+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1271}
{"time":"2025-07-28T19:08:23.385185+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:23.385241+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:23.426993+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":41}
{"time":"2025-07-28T19:08:23.427017+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:08:23 [akrotiri/nRQLu4lSAJ-000215] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3757B in 1.101775792s
{"time":"2025-07-28T19:08:23.468659+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":41}
{"time":"2025-07-28T19:08:23.468676+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":6645,"success":6645,"duration_ms":1399}
2025/07/28 19:08:23 [akrotiri/nRQLu4lSAJ-000216] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3754B in 1.089047958s
{"time":"2025-07-28T19:08:23.874899+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:23.874925+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000217] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 1.076448041s
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000218] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 1.089797375s
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000219] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 969.097417ms
{"time":"2025-07-28T19:08:24.327552+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000220] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3759B in 1.062289917s
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000221] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3760B in 1.062829042s
2025/07/28 19:08:24 [akrotiri/nRQLu4lSAJ-000222] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3760B in 1.076154292s
{"time":"2025-07-28T19:08:24.664824+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000223] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3763B in 1.108321583s
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000224] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3763B in 1.109602042s
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000225] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3763B in 1.052190333s
{"time":"2025-07-28T19:08:25.335737+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1460}
{"time":"2025-07-28T19:08:25.335757+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:25.335804+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:25.344238+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":8}
{"time":"2025-07-28T19:08:25.344271+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000226] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3760B in 1.09577275s
{"time":"2025-07-28T19:08:25.48333+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":139}
{"time":"2025-07-28T19:08:25.483757+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:25.490088+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":6}
{"time":"2025-07-28T19:08:25.490105+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20013,"unique_prefixes":8865,"success":8865,"duration_ms":1629}
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000227] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3754B in 1.064976958s
2025/07/28 19:08:25 [akrotiri/nRQLu4lSAJ-000228] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3754B in 1.1105515s
{"time":"2025-07-28T19:08:26.004312+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":50000442125,"total_messages":245593,"total_bytes":177028891,"total_mb":"168.83","messages_per_sec":"2661.85","bits_per_sec":"15336850","mbps":"15.34","total_dropped":0}
{"time":"2025-07-28T19:08:26.004347+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":243142,"dropped":0,"avg_time":133166,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:26.004358+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":243142,"dropped":0,"avg_time":58151,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:26.004366+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":243142,"dropped":0,"avg_time":165693,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:26.004373+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":243142,"dropped":0,"avg_time":2069,"min_time":0,"max_time":20882459}
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000229] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 1.041385416s
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000230] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 1.063147166s
{"time":"2025-07-28T19:08:26.29021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:26.290227+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:26.336384+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":46}
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000231] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 1.095675833s
{"time":"2025-07-28T19:08:26.39104+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"80.81.194.204","peer_asn":"48166"}
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000232] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3753B in 963.227ms
{"time":"2025-07-28T19:08:26.552771+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:26.552788+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000233] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3755B in 999.683292ms
2025/07/28 19:08:26 [akrotiri/nRQLu4lSAJ-000234] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3756B in 1.023684542s
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000235] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3757B in 1.087896542s
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000236] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3757B in 1.071200959s
{"time":"2025-07-28T19:08:27.389095+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000237] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3758B in 1.094182709s
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000238] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3758B in 1.073683959s
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000239] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3759B in 1.098977792s
{"time":"2025-07-28T19:08:27.76415+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:27.764158+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1211}
{"time":"2025-07-28T19:08:27.764184+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:27.778124+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":13}
{"time":"2025-07-28T19:08:27.778143+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:27.787948+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":9}
{"time":"2025-07-28T19:08:27.787966+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":6135,"success":6135,"duration_ms":1243}
{"time":"2025-07-28T19:08:27.813536+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:27.813549+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:27 [akrotiri/nRQLu4lSAJ-000240] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3755B in 1.074659375s
{"time":"2025-07-28T19:08:27.871822+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":58}
{"time":"2025-07-28T19:08:28.277914+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
{"time":"2025-07-28T19:08:28.282425+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000241] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 1.061955042s
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000242] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 1.080827333s
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000243] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 1.051267292s
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000244] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3754B in 1.018064334s
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000245] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3753B in 982.598916ms
2025/07/28 19:08:28 [akrotiri/nRQLu4lSAJ-000246] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59428 - 200 3753B in 960.169333ms
{"time":"2025-07-28T19:08:28.828053+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:28.828081+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:28.947988+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":119}
2025/07/28 19:08:29 [akrotiri/nRQLu4lSAJ-000247] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 899.490792ms
2025/07/28 19:08:29 [akrotiri/nRQLu4lSAJ-000248] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3753B in 886.198958ms
{"time":"2025-07-28T19:08:29.38112+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:29.381147+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:29 [akrotiri/nRQLu4lSAJ-000249] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3755B in 864.334ms
2025/07/28 19:08:29 [akrotiri/nRQLu4lSAJ-000250] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59433 - 200 3755B in 871.581417ms
{"time":"2025-07-28T19:08:29.417747+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:29 [akrotiri/nRQLu4lSAJ-000251] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59434 - 200 3758B in 746.747542ms
{"time":"2025-07-28T19:08:29.790615+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":409}
{"time":"2025-07-28T19:08:29.79064+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:29.790622+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:29.793977+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:08:29.793999+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:29.83782+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":43}
{"time":"2025-07-28T19:08:29.837835+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20009,"unique_prefixes":9043,"success":9043,"duration_ms":466}
{"time":"2025-07-28T19:08:29.865667+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:29.865685+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:29.900598+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":34}
{"time":"2025-07-28T19:08:29.940564+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:29.940581+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:30 [akrotiri/nRQLu4lSAJ-000252] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 673.332625ms
{"time":"2025-07-28T19:08:30.330755+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":390}
{"time":"2025-07-28T19:08:30.330772+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:30.330776+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:30.369903+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":39}
{"time":"2025-07-28T19:08:30.369921+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20007,"unique_prefixes":17330,"success":17330,"duration_ms":443}
{"time":"2025-07-28T19:08:30.430228+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:30.43024+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:30.463905+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":33}
{"time":"2025-07-28T19:08:30.600148+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:30.600164+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:30 [akrotiri/nRQLu4lSAJ-000253] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 658.970167ms
{"time":"2025-07-28T19:08:30.650478+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:31.002825+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":402}
{"time":"2025-07-28T19:08:31.002851+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:31.002833+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:31.005408+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":2}
{"time":"2025-07-28T19:08:31.005445+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:31.007851+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":2}
{"time":"2025-07-28T19:08:31.00786+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":17577,"success":17577,"duration_ms":419}
2025/07/28 19:08:31 [akrotiri/nRQLu4lSAJ-000254] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3751B in 640.66375ms
{"time":"2025-07-28T19:08:31.131814+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:31.131826+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:31.209497+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":77}
{"time":"2025-07-28T19:08:31.394478+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:31.394493+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:31 [akrotiri/nRQLu4lSAJ-000255] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3755B in 648.955208ms
{"time":"2025-07-28T19:08:31.961427+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:32.052114+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:32 [akrotiri/nRQLu4lSAJ-000256] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3761B in 729.255584ms
2025/07/28 19:08:32 [akrotiri/nRQLu4lSAJ-000257] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3761B in 662.749375ms
{"time":"2025-07-28T19:08:32.742275+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1347}
{"time":"2025-07-28T19:08:32.742294+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:32.742311+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:32.921695+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":179}
{"time":"2025-07-28T19:08:32.921709+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:32.922853+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:32.923575+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":1}
{"time":"2025-07-28T19:08:32.923594+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:32.928459+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":4}
{"time":"2025-07-28T19:08:32.928466+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:32.928471+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":16497,"success":16497,"duration_ms":1543}
{"time":"2025-07-28T19:08:32.942775+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:32.985476+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":57}
{"time":"2025-07-28T19:08:32.985489+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:33 [akrotiri/nRQLu4lSAJ-000258] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 714.2415ms
{"time":"2025-07-28T19:08:33.653594+02:00","level":"DEBUG","msg":"System stats","source":"cli.go:40","func":"routewatch.logDebugStats","goroutines":83,"alloc_mb":97,"total_alloc_mb":1720,"sys_mb":137,"num_gc":49,"heap_alloc_mb":97,"heap_sys_mb":125,"heap_idle_mb":22,"heap_inuse_mb":102,"heap_released_mb":15,"stack_inuse_mb":2}
2025/07/28 19:08:33 [akrotiri/nRQLu4lSAJ-000259] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3755B in 690.170375ms
{"time":"2025-07-28T19:08:34.023451+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:34 [akrotiri/nRQLu4lSAJ-000260] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3757B in 639.157458ms
{"time":"2025-07-28T19:08:34.120439+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:34.563495+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1577}
{"time":"2025-07-28T19:08:34.563515+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:34.56352+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:34.645032+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":81}
{"time":"2025-07-28T19:08:34.645035+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:34.64928+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":4}
{"time":"2025-07-28T19:08:34.649303+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:34.65688+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":7}
{"time":"2025-07-28T19:08:34.656894+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20007,"unique_prefixes":17320,"success":17320,"duration_ms":1727}
{"time":"2025-07-28T19:08:34.664534+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:34.664547+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:34 [akrotiri/nRQLu4lSAJ-000261] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 736.743708ms
{"time":"2025-07-28T19:08:34.818992+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:35.035348+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:1042:1","peer_asn":"31042"}
2025/07/28 19:08:35 [akrotiri/nRQLu4lSAJ-000262] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3758B in 787.74675ms
{"time":"2025-07-28T19:08:35.647681+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:35.647681+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":983}
{"time":"2025-07-28T19:08:35.64773+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:08:35 [akrotiri/nRQLu4lSAJ-000263] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3759B in 702.227791ms
{"time":"2025-07-28T19:08:35.791126+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:35.791122+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":143}
{"time":"2025-07-28T19:08:35.79726+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":6}
{"time":"2025-07-28T19:08:35.797272+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":7951,"success":7951,"duration_ms":1139}
{"time":"2025-07-28T19:08:35.802998+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:35.803009+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:36.004086+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":60000166625,"total_messages":297984,"total_bytes":216255311,"total_mb":"206.24","messages_per_sec":"3040.71","bits_per_sec":"17698667","mbps":"17.70","total_dropped":0}
{"time":"2025-07-28T19:08:36.004107+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":295105,"dropped":0,"avg_time":119904,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:36.004112+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":295105,"dropped":0,"avg_time":56514,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:36.004115+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":961,"queue_cap":100000,"processed":294143,"dropped":0,"avg_time":160729,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:36.004118+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":295105,"dropped":0,"avg_time":2031,"min_time":0,"max_time":20882459}
{"time":"2025-07-28T19:08:36.203492+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:36.338531+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"217.29.66.232","peer_asn":"54104"}
{"time":"2025-07-28T19:08:36.341477+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
2025/07/28 19:08:36 [akrotiri/nRQLu4lSAJ-000264] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3759B in 860.047708ms
{"time":"2025-07-28T19:08:36.522808+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:36.52284+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":719}
{"time":"2025-07-28T19:08:36.522876+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:36.561225+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":38}
{"time":"2025-07-28T19:08:36.561266+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:36.56591+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":4}
{"time":"2025-07-28T19:08:36.565945+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:36.570159+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":4}
{"time":"2025-07-28T19:08:36.570169+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":5742,"success":5742,"duration_ms":771}
2025/07/28 19:08:36 [akrotiri/nRQLu4lSAJ-000265] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3752B in 739.382417ms
{"time":"2025-07-28T19:08:37.417883+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:37.417898+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:37 [akrotiri/nRQLu4lSAJ-000266] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 623.284125ms
{"time":"2025-07-28T19:08:37.498092+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":80}
2025/07/28 19:08:37 [akrotiri/nRQLu4lSAJ-000267] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 622.882375ms
{"time":"2025-07-28T19:08:37.667058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:37.667078+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:37.736365+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"195.208.208.187","peer_asn":"9002"}
2025/07/28 19:08:38 [akrotiri/nRQLu4lSAJ-000268] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 645.478791ms
{"time":"2025-07-28T19:08:38.324788+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":657}
{"time":"2025-07-28T19:08:38.324804+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:38.324808+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:38.415062+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":90}
{"time":"2025-07-28T19:08:38.415082+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":16418,"unique_prefixes":7199,"success":7199,"duration_ms":752}
{"time":"2025-07-28T19:08:38.519524+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:38.519537+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:38.563551+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":44}
{"time":"2025-07-28T19:08:38.619037+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:38.619054+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:38.625245+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":6}
2025/07/28 19:08:38 [akrotiri/nRQLu4lSAJ-000269] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3753B in 640.730292ms
2025/07/28 19:08:39 [akrotiri/nRQLu4lSAJ-000270] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 679.340083ms
2025/07/28 19:08:39 [akrotiri/nRQLu4lSAJ-000271] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 648.752416ms
{"time":"2025-07-28T19:08:39.665076+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:39.665087+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:40.021877+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":356}
{"time":"2025-07-28T19:08:40.021894+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:40.021901+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:40.075277+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:40.075856+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":53}
{"time":"2025-07-28T19:08:40.07587+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":12790,"unique_prefixes":3484,"success":3484,"duration_ms":413}
{"time":"2025-07-28T19:08:40.07588+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:40.10634+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":30}
2025/07/28 19:08:40 [akrotiri/nRQLu4lSAJ-000272] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 703.211584ms
{"time":"2025-07-28T19:08:40.62553+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"80.81.192.113","peer_asn":"35320"}
2025/07/28 19:08:40 [akrotiri/nRQLu4lSAJ-000273] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 663.594ms
{"time":"2025-07-28T19:08:40.871914+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:40.871926+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:40.905366+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:40.913924+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":41}
{"time":"2025-07-28T19:08:40.91393+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:40.917132+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
2025/07/28 19:08:41 [akrotiri/nRQLu4lSAJ-000274] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 646.394666ms
{"time":"2025-07-28T19:08:41.216624+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"196.60.8.170","peer_asn":"327781"}
2025/07/28 19:08:41 [akrotiri/nRQLu4lSAJ-000275] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 600.239208ms
{"time":"2025-07-28T19:08:41.668475+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:41.66849+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:42.115819+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:42 [akrotiri/nRQLu4lSAJ-000276] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3759B in 586.912ms
{"time":"2025-07-28T19:08:42.472822+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:42.472819+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":804}
{"time":"2025-07-28T19:08:42.472861+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:42.510436+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":37}
{"time":"2025-07-28T19:08:42.510447+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:42.513694+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":3}
{"time":"2025-07-28T19:08:42.513706+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":19350,"unique_prefixes":7616,"success":7616,"duration_ms":850}
2025/07/28 19:08:42 [akrotiri/nRQLu4lSAJ-000277] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 672.594416ms
{"time":"2025-07-28T19:08:42.89924+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:42.899255+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:42.918192+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:42.991005+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":91}
{"time":"2025-07-28T19:08:42.991014+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:42.994176+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
2025/07/28 19:08:43 [akrotiri/nRQLu4lSAJ-000278] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 619.220584ms
2025/07/28 19:08:43 [akrotiri/nRQLu4lSAJ-000279] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3752B in 592.1105ms
{"time":"2025-07-28T19:08:43.667804+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:43.667818+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:44 [akrotiri/nRQLu4lSAJ-000280] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3751B in 651.86725ms
{"time":"2025-07-28T19:08:44.465271+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":797}
{"time":"2025-07-28T19:08:44.465312+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:44.465316+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:44.467972+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:44.475088+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":9}
{"time":"2025-07-28T19:08:44.475096+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:44.4751+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":18694,"unique_prefixes":6390,"success":6390,"duration_ms":812}
{"time":"2025-07-28T19:08:44.599514+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":124}
2025/07/28 19:08:44 [akrotiri/nRQLu4lSAJ-000281] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3749B in 801.422083ms
2025/07/28 19:08:45 [akrotiri/nRQLu4lSAJ-000282] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3749B in 604.868ms
{"time":"2025-07-28T19:08:45.580503+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:45.580522+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:45.601613+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:45.608413+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:45 [akrotiri/nRQLu4lSAJ-000283] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3755B in 556.036542ms
{"time":"2025-07-28T19:08:45.61972+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":39}
{"time":"2025-07-28T19:08:45.619728+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:45.622759+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":3}
{"time":"2025-07-28T19:08:45.622778+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:46.004541+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":70000555625,"total_messages":342016,"total_bytes":247383573,"total_mb":"235.92","messages_per_sec":"3247.06","bits_per_sec":"18750228","mbps":"18.75","total_dropped":0}
{"time":"2025-07-28T19:08:46.004577+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":338648,"dropped":0,"avg_time":108108,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:46.004582+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":338648,"dropped":0,"avg_time":50285,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:46.004591+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":1218,"queue_cap":100000,"processed":337429,"dropped":0,"avg_time":148948,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:46.004595+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":338648,"dropped":0,"avg_time":1943,"min_time":0,"max_time":20882459}
2025/07/28 19:08:46 [akrotiri/nRQLu4lSAJ-000284] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3753B in 725.505083ms
{"time":"2025-07-28T19:08:46.740561+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":1117}
{"time":"2025-07-28T19:08:46.74058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:46.740584+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:46.764025+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":23}
{"time":"2025-07-28T19:08:46.764041+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":10148,"success":10148,"duration_ms":1164}
2025/07/28 19:08:46 [akrotiri/nRQLu4lSAJ-000285] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3750B in 767.819125ms
2025/07/28 19:08:47 [akrotiri/nRQLu4lSAJ-000286] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3750B in 627.9065ms
{"time":"2025-07-28T19:08:47.191751+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:47.191762+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:47.265205+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":73}
{"time":"2025-07-28T19:08:47.659933+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:47.659959+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:47.665859+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":5}
2025/07/28 19:08:47 [akrotiri/nRQLu4lSAJ-000287] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3751B in 759.642167ms
2025/07/28 19:08:48 [akrotiri/nRQLu4lSAJ-000288] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3751B in 741.929583ms
{"time":"2025-07-28T19:08:48.655502+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:48.655522+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:48.668122+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:48.68021+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":24}
{"time":"2025-07-28T19:08:48.680245+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:49 [akrotiri/nRQLu4lSAJ-000289] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3758B in 1.008004166s
{"time":"2025-07-28T19:08:49.121517+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:432","func":"streamer.(*Streamer).stream","peer":"195.208.209.174","peer_asn":"25227"}
2025/07/28 19:08:49 [akrotiri/nRQLu4lSAJ-000290] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3757B in 850.304916ms
{"time":"2025-07-28T19:08:49.676251+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":995}
{"time":"2025-07-28T19:08:49.676268+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:49.676272+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
2025/07/28 19:08:49 [akrotiri/nRQLu4lSAJ-000291] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3758B in 667.173666ms
{"time":"2025-07-28T19:08:49.830118+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":153}
{"time":"2025-07-28T19:08:49.830136+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":17606,"unique_prefixes":4260,"success":4260,"duration_ms":1167}
{"time":"2025-07-28T19:08:49.991001+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:49.991015+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:50.027158+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":36}
{"time":"2025-07-28T19:08:50.137902+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:440","func":"streamer.(*Streamer).stream","peer":"193.239.118.249","peer_asn":"41255"}
2025/07/28 19:08:50 [akrotiri/nRQLu4lSAJ-000292] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3755B in 632.136875ms
{"time":"2025-07-28T19:08:50.236264+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:50.236276+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:50.241092+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":4}
2025/07/28 19:08:50 [akrotiri/nRQLu4lSAJ-000293] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3755B in 630.333416ms
2025/07/28 19:08:51 [akrotiri/nRQLu4lSAJ-000294] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3755B in 645.829ms
{"time":"2025-07-28T19:08:51.665972+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
{"time":"2025-07-28T19:08:51.666134+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:180"}
2025/07/28 19:08:51 [akrotiri/nRQLu4lSAJ-000295] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3755B in 668.391125ms
{"time":"2025-07-28T19:08:52.041884+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:180)","duration_ms":375}
{"time":"2025-07-28T19:08:52.041917+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:52.041921+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:261"}
{"time":"2025-07-28T19:08:52.085899+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:261)","duration_ms":43}
{"time":"2025-07-28T19:08:52.085917+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":12099,"unique_prefixes":1903,"success":1903,"duration_ms":422}
2025/07/28 19:08:52 [akrotiri/nRQLu4lSAJ-000296] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3755B in 629.8825ms
2025/07/28 19:08:52 [akrotiri/nRQLu4lSAJ-000297] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3755B in 595.469584ms
2025/07/28 19:08:53 [akrotiri/nRQLu4lSAJ-000298] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3755B in 578.853125ms
{"time":"2025-07-28T19:08:53.659722+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:53.659738+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:639"}
{"time":"2025-07-28T19:08:53.659846+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:143","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
{"time":"2025-07-28T19:08:53.66108+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:639)","duration_ms":1}
{"time":"2025-07-28T19:08:53.66109+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:149","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:331"}
2025/07/28 19:08:53 [akrotiri/nRQLu4lSAJ-000299] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3755B in 578.871ms
{"time":"2025-07-28T19:08:53.67232+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:161","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:331)","duration_ms":11}
2025/07/28 19:08:54 [akrotiri/nRQLu4lSAJ-000300] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 588.576375ms
2025/07/28 19:08:54 [akrotiri/nRQLu4lSAJ-000301] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3753B in 573.700125ms
2025/07/28 19:08:55 [akrotiri/nRQLu4lSAJ-000302] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3753B in 623.384583ms
2025/07/28 19:08:55 [akrotiri/nRQLu4lSAJ-000303] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 667.114542ms
{"time":"2025-07-28T19:08:56.005092+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":80001029625,"total_messages":357547,"total_bytes":258343631,"total_mb":"246.38","messages_per_sec":"3119.43","bits_per_sec":"17999429","mbps":"18.00","total_dropped":0}
{"time":"2025-07-28T19:08:56.005113+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":103823,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:08:56.005117+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":48134,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:08:56.005121+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":148552,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:08:56.005124+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":1920,"min_time":0,"max_time":20882459}
2025/07/28 19:08:56 [akrotiri/nRQLu4lSAJ-000304] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3753B in 660.096375ms
2025/07/28 19:08:56 [akrotiri/nRQLu4lSAJ-000305] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3753B in 690.7415ms
2025/07/28 19:08:57 [akrotiri/nRQLu4lSAJ-000306] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 679.979ms
2025/07/28 19:08:57 [akrotiri/nRQLu4lSAJ-000307] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3753B in 589.36475ms
2025/07/28 19:08:58 [akrotiri/nRQLu4lSAJ-000308] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3753B in 577.09975ms
2025/07/28 19:08:58 [akrotiri/nRQLu4lSAJ-000309] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3753B in 583.525917ms
2025/07/28 19:08:59 [akrotiri/nRQLu4lSAJ-000310] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 576.991042ms
2025/07/28 19:08:59 [akrotiri/nRQLu4lSAJ-000311] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 594.249ms
2025/07/28 19:09:00 [akrotiri/nRQLu4lSAJ-000312] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 612.268ms
2025/07/28 19:09:00 [akrotiri/nRQLu4lSAJ-000313] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 593.98125ms
2025/07/28 19:09:01 [akrotiri/nRQLu4lSAJ-000314] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 614.519959ms
2025/07/28 19:09:01 [akrotiri/nRQLu4lSAJ-000315] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 607.626917ms
2025/07/28 19:09:02 [akrotiri/nRQLu4lSAJ-000316] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 600.766875ms
2025/07/28 19:09:02 [akrotiri/nRQLu4lSAJ-000317] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 599.535458ms
2025/07/28 19:09:03 [akrotiri/nRQLu4lSAJ-000318] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 582.233042ms
2025/07/28 19:09:03 [akrotiri/nRQLu4lSAJ-000319] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 582.717875ms
2025/07/28 19:09:04 [akrotiri/nRQLu4lSAJ-000320] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3755B in 586.526209ms
2025/07/28 19:09:04 [akrotiri/nRQLu4lSAJ-000321] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 574.299083ms
2025/07/28 19:09:05 [akrotiri/nRQLu4lSAJ-000322] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 571.166083ms
2025/07/28 19:09:05 [akrotiri/nRQLu4lSAJ-000323] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 575.013625ms
{"time":"2025-07-28T19:09:06.005175+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":90001031000,"total_messages":357547,"total_bytes":258343631,"total_mb":"246.38","messages_per_sec":"2640.54","bits_per_sec":"15236187","mbps":"15.24","total_dropped":0}
{"time":"2025-07-28T19:09:06.005194+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":103823,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:09:06.005199+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":48134,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:09:06.005203+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":148552,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:09:06.005206+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":1920,"min_time":0,"max_time":20882459}
2025/07/28 19:09:06 [akrotiri/nRQLu4lSAJ-000324] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 592.732292ms
2025/07/28 19:09:07 [akrotiri/nRQLu4lSAJ-000325] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 622.906708ms
2025/07/28 19:09:07 [akrotiri/nRQLu4lSAJ-000326] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 610.983083ms
2025/07/28 19:09:07 [akrotiri/nRQLu4lSAJ-000327] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 582.094333ms
2025/07/28 19:09:08 [akrotiri/nRQLu4lSAJ-000328] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 576.862875ms
2025/07/28 19:09:08 [akrotiri/nRQLu4lSAJ-000329] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 582.205209ms
2025/07/28 19:09:09 [akrotiri/nRQLu4lSAJ-000330] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 581.30425ms
2025/07/28 19:09:09 [akrotiri/nRQLu4lSAJ-000331] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 575.841083ms
2025/07/28 19:09:10 [akrotiri/nRQLu4lSAJ-000332] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 615.411584ms
2025/07/28 19:09:10 [akrotiri/nRQLu4lSAJ-000333] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 591.091375ms
2025/07/28 19:09:11 [akrotiri/nRQLu4lSAJ-000334] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 576.625791ms
2025/07/28 19:09:11 [akrotiri/nRQLu4lSAJ-000335] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 594.505666ms
2025/07/28 19:09:12 [akrotiri/nRQLu4lSAJ-000336] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 583.306917ms
2025/07/28 19:09:12 [akrotiri/nRQLu4lSAJ-000337] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 582.966709ms
2025/07/28 19:09:13 [akrotiri/nRQLu4lSAJ-000338] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3754B in 598.679292ms
2025/07/28 19:09:13 [akrotiri/nRQLu4lSAJ-000339] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 581.196667ms
2025/07/28 19:09:14 [akrotiri/nRQLu4lSAJ-000340] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 578.802541ms
2025/07/28 19:09:14 [akrotiri/nRQLu4lSAJ-000341] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 578.907333ms
2025/07/28 19:09:15 [akrotiri/nRQLu4lSAJ-000342] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 577.879417ms
2025/07/28 19:09:15 [akrotiri/nRQLu4lSAJ-000343] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 575.945417ms
{"time":"2025-07-28T19:09:16.005249+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":100001037208,"total_messages":357547,"total_bytes":258343631,"total_mb":"246.38","messages_per_sec":"2235.17","bits_per_sec":"12897154","mbps":"12.90","total_dropped":0}
{"time":"2025-07-28T19:09:16.005286+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":103823,"min_time":0,"max_time":2800460167}
{"time":"2025-07-28T19:09:16.005293+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":48134,"min_time":0,"max_time":2023266000}
{"time":"2025-07-28T19:09:16.005297+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":148552,"min_time":0,"max_time":3084562375}
{"time":"2025-07-28T19:09:16.0053+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":353961,"dropped":0,"avg_time":1920,"min_time":0,"max_time":20882459}
2025/07/28 19:09:16 [akrotiri/nRQLu4lSAJ-000344] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 589.83175ms
2025/07/28 19:09:16 [akrotiri/nRQLu4lSAJ-000345] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 590.129042ms
2025/07/28 19:09:17 [akrotiri/nRQLu4lSAJ-000346] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 572.234916ms
2025/07/28 19:09:17 [akrotiri/nRQLu4lSAJ-000347] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 603.296084ms
2025/07/28 19:09:18 [akrotiri/nRQLu4lSAJ-000348] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3756B in 580.68025ms
2025/07/28 19:09:18 [akrotiri/nRQLu4lSAJ-000349] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3756B in 578.744958ms
2025/07/28 19:09:19 [akrotiri/nRQLu4lSAJ-000350] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59432 - 200 3756B in 592.029ms
2025/07/28 19:09:19 [akrotiri/nRQLu4lSAJ-000351] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59431 - 200 3754B in 594.455667ms
2025/07/28 19:09:20 [akrotiri/nRQLu4lSAJ-000352] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:59430 - 200 3754B in 593.041041ms
Failed to parse JSON: unexpected end of JSON input
Raw line: {"type":"ris_message",
panic: JSON parse error: unexpected end of JSON input
goroutine 44 [running]:
git.eeqj.de/sneak/routewatch/internal/streamer.(*Streamer).stream(0x140000cf340, {0x102d36a70, 0x140000d6050})
/Users/user/dev/routewatch/internal/streamer/streamer.go:400 +0xd30
git.eeqj.de/sneak/routewatch/internal/streamer.(*Streamer).Start.func1()
/Users/user/dev/routewatch/internal/streamer/streamer.go:138 +0x2c
created by git.eeqj.de/sneak/routewatch/internal/streamer.(*Streamer).Start in goroutine 22
/Users/user/dev/routewatch/internal/streamer/streamer.go:137 +0x1f8
Reference in New Issue View Git Blame Copy Permalink