sneak/routewatch
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
3673264552
routewatch/log.txt
sneak 3673264552 Separate IPv4 and IPv6 routes into different tables 
- Create live_routes_v4 and live_routes_v6 tables
- Update all database methods to use appropriate table
- Add IP version detection in database queries
- Remove filtering by ip_version column for better performance
- Fix route count queries that were timing out
- Update PrefixHandler to include IP version in deletions
2025-07-28 22:29:15 +02:00

353 lines
69 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 7.292µ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 7.042µ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 6.375µs
[Fx] BEFORE RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
{"time":"2025-07-28T22:18:29.444422+02:00","level":"INFO","msg":"Opening database","source":"database.go:64","func":"database.New","path":"/Users/user/Library/Application Support/berlin.sneak.app.routewatch/db.sqlite"}
{"time":"2025-07-28T22:18:29.589748+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"PRAGMA wal_checkpoint(TRUNCATE)","duration":143939291}
{"time":"2025-07-28T22:18:29.589952+02:00","level":"INFO","msg":"Running VACUUM to optimize database (this may take a moment)","source":"database.go:128","func":"database.(*Database).Initialize"}
{"time":"2025-07-28T22:18:49.974864+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"VACUUM","duration":20382446209}
[Fx] RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]]) in 20.532845583s
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New() in 362.958µ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 220µ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 163.042µ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 7.959µs
[Fx] BEFORE RUN provide: go.uber.org/fx.(*App).shutdowner-fm()
[Fx] RUN provide: go.uber.org/fx.(*App).shutdowner-fm() in 6.417µ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 198.709µs
[Fx] RUNNING
{"time":"2025-07-28T22:18:49.98229+02:00","level":"INFO","msg":"Starting RouteWatch","source":"app.go:64","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:18:49.982304+02:00","level":"INFO","msg":"Using batched database handlers for improved performance","source":"app.go:76","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:18:49.984+02:00","level":"INFO","msg":"Starting HTTP server","source":"server.go:52","func":"server.(*Server).Start","port":"8080"}
{"time":"2025-07-28T22:18:50.085614+02:00","level":"INFO","msg":"Connected to RIS Live stream","source":"streamer.go:421","func":"streamer.(*Streamer).stream"}
2025/07/28 22:18:50 [akrotiri/XuQmuO84Kd-000001] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3643B in 636.210708ms
{"time":"2025-07-28T22:18:50.733692+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.81.194.190","peer_asn":"31042"}
{"time":"2025-07-28T22:18:50.989529+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:50.989543+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:51.155955+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
2025/07/28 22:18:51 [akrotiri/XuQmuO84Kd-000002] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52916 - 200 3662B in 889.800666ms
2025/07/28 22:18:51 [akrotiri/XuQmuO84Kd-000003] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3662B in 868.27775ms
{"time":"2025-07-28T22:18:51.983703+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
2025/07/28 22:18:52 [akrotiri/XuQmuO84Kd-000004] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52916 - 200 3666B in 790.335875ms
{"time":"2025-07-28T22:18:52.889695+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"195.208.208.187","peer_asn":"9002"}
2025/07/28 22:18:52 [akrotiri/XuQmuO84Kd-000005] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3667B in 848.509083ms
{"time":"2025-07-28T22:18:53.342162+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":2352}
{"time":"2025-07-28T22:18:53.342191+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:53.342196+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:53.345637+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:53.345664+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":3}
{"time":"2025-07-28T22:18:53.345689+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":11218,"unique_prefixes":6009,"success":6009,"duration_ms":2361}
{"time":"2025-07-28T22:18:53.549051+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:18:53 [akrotiri/XuQmuO84Kd-000006] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3663B in 1.000552959s
{"time":"2025-07-28T22:18:53.730014+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:53.730025+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":384}
{"time":"2025-07-28T22:18:53.731335+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:53.737752+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":7}
{"time":"2025-07-28T22:18:53.737762+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:53.745262+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:18:53 [akrotiri/XuQmuO84Kd-000007] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52918 - 200 3673B in 1.000698292s
{"time":"2025-07-28T22:18:53.763257+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":25}
{"time":"2025-07-28T22:18:53.764968+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:53.764981+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:54.097278+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:54.152016+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:54.17025+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":405}
{"time":"2025-07-28T22:18:54.170308+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:54.193492+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:18:54 [akrotiri/XuQmuO84Kd-000008] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3675B in 1.001490167s
{"time":"2025-07-28T22:18:54.268091+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:54.288287+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"217.29.66.232","peer_asn":"54104"}
{"time":"2025-07-28T22:18:54.551604+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:18:54 [akrotiri/XuQmuO84Kd-000009] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52916 - 200 3715B in 1.000694625s
2025/07/28 22:18:54 [akrotiri/XuQmuO84Kd-000010] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3726B in 938.313458ms
{"time":"2025-07-28T22:18:55.130594+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":960}
{"time":"2025-07-28T22:18:55.130606+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:55.130613+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:55.134492+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":3}
{"time":"2025-07-28T22:18:55.134507+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:55.159562+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:55.159611+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":25}
{"time":"2025-07-28T22:18:55.161187+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:55.176379+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":16}
{"time":"2025-07-28T22:18:55.176394+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25001,"unique_prefixes":2232,"success":2232,"duration_ms":1084}
{"time":"2025-07-28T22:18:55.176457+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:55.221595+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":45}
2025/07/28 22:18:55 [akrotiri/XuQmuO84Kd-000011] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3750B in 852.23125ms
{"time":"2025-07-28T22:18:55.730933+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:55.73095+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:55.760852+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:55.858125+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
2025/07/28 22:18:55 [akrotiri/XuQmuO84Kd-000012] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3758B in 851.020291ms
{"time":"2025-07-28T22:18:56.331469+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"196.60.8.170","peer_asn":"327781"}
2025/07/28 22:18:56 [akrotiri/XuQmuO84Kd-000013] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3760B in 1.00044125s
{"time":"2025-07-28T22:18:56.823899+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:18:56 [akrotiri/XuQmuO84Kd-000014] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52920 - 200 3748B in 1.000846833s
{"time":"2025-07-28T22:18:56.829878+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8::7942:0:1","peer_asn":"31042"}
{"time":"2025-07-28T22:18:57.029134+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:18:57 [akrotiri/XuQmuO84Kd-000015] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3748B in 1.001558292s
{"time":"2025-07-28T22:18:57.502693+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":1771}
{"time":"2025-07-28T22:18:57.502714+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:57.50272+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:57.533632+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:18:57 [akrotiri/XuQmuO84Kd-000016] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3748B in 1.001396375s
{"time":"2025-07-28T22:18:57.641027+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:57.641049+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":138}
{"time":"2025-07-28T22:18:57.641064+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25010,"unique_prefixes":10409,"success":10409,"duration_ms":1920}
{"time":"2025-07-28T22:18:57.687584+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:57.687605+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":46}
{"time":"2025-07-28T22:18:57.689197+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:57.69241+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":4}
{"time":"2025-07-28T22:18:57.692421+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:57.73752+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":45}
{"time":"2025-07-28T22:18:57.738992+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:57.739003+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:57.767916+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":28}
{"time":"2025-07-28T22:18:57.81553+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:57.815579+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:57.954042+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:57.971603+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"80.81.192.113","peer_asn":"35320"}
2025/07/28 22:18:58 [akrotiri/XuQmuO84Kd-000017] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3755B in 964.940333ms
{"time":"2025-07-28T22:18:58.488729+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
2025/07/28 22:18:58 [akrotiri/XuQmuO84Kd-000018] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3758B in 986.669625ms
2025/07/28 22:18:58 [akrotiri/XuQmuO84Kd-000019] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3759B in 920.961542ms
{"time":"2025-07-28T22:18:59.037499+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":1221}
{"time":"2025-07-28T22:18:59.037519+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:59.037505+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:59.042225+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":4}
{"time":"2025-07-28T22:18:59.042294+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:59.077358+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2405:a640::50","peer_asn":"38855"}
{"time":"2025-07-28T22:18:59.083036+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":40}
{"time":"2025-07-28T22:18:59.08304+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:59.084209+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:59.100083+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":17}
{"time":"2025-07-28T22:18:59.100101+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":7910,"success":7910,"duration_ms":1294}
{"time":"2025-07-28T22:18:59.100151+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:59.107488+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:59.121956+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":21}
{"time":"2025-07-28T22:18:59.121971+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:18:59.325762+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
2025/07/28 22:18:59 [akrotiri/XuQmuO84Kd-000020] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3755B in 936.035042ms
{"time":"2025-07-28T22:18:59.604668+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:59.926905+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":804}
{"time":"2025-07-28T22:18:59.926917+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:18:59.926925+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:59.931163+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":4}
{"time":"2025-07-28T22:18:59.931216+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:18:59.979959+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":48}
{"time":"2025-07-28T22:18:59.979979+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:18:59.987432+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":7}
{"time":"2025-07-28T22:18:59.987448+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25039,"unique_prefixes":5378,"success":5378,"duration_ms":885}
2025/07/28 22:19:00 [akrotiri/XuQmuO84Kd-000021] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3749B in 964.686958ms
{"time":"2025-07-28T22:19:00.085747+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":10000037583,"total_messages":51295,"total_bytes":37676708,"total_mb":"35.93","messages_per_sec":"761.77","bits_per_sec":"4478715","mbps":"4.48","total_dropped":0}
{"time":"2025-07-28T22:19:00.085771+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":50793,"dropped":0,"avg_time":137610,"min_time":0,"max_time":2575248875}
{"time":"2025-07-28T22:19:00.085807+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":50794,"dropped":0,"avg_time":121666,"min_time":0,"max_time":1835761334}
{"time":"2025-07-28T22:19:00.085816+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":2,"queue_cap":100000,"processed":50793,"dropped":0,"avg_time":145796,"min_time":0,"max_time":2210706750}
{"time":"2025-07-28T22:19:00.085822+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":2,"queue_cap":100000,"processed":50794,"dropped":0,"avg_time":1398,"min_time":0,"max_time":743833}
{"time":"2025-07-28T22:19:00.149123+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:00.14914+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:00.526898+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:00.549952+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:00 [akrotiri/XuQmuO84Kd-000022] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3742B in 1.002468791s
{"time":"2025-07-28T22:19:00.975044+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:01.046847+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:01 [akrotiri/XuQmuO84Kd-000023] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3745B in 1.001907459s
{"time":"2025-07-28T22:19:01.111256+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":962}
{"time":"2025-07-28T22:19:01.111287+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:01.111296+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:01.132301+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:01.132351+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":20}
{"time":"2025-07-28T22:19:01.132379+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":8995,"success":8995,"duration_ms":992}
{"time":"2025-07-28T22:19:01.145107+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:01.174568+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:01.174568+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":42}
{"time":"2025-07-28T22:19:01.17714+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:01.181212+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:01.181223+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":6}
{"time":"2025-07-28T22:19:01.556044+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:19:01 [akrotiri/XuQmuO84Kd-000024] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 0B in 1.000137667s
{"time":"2025-07-28T22:19:01.69539+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:01.695391+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":514}
{"time":"2025-07-28T22:19:01.695464+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:01.772156+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":76}
{"time":"2025-07-28T22:19:01.772172+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:01.783627+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":11}
{"time":"2025-07-28T22:19:01.78364+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25010,"unique_prefixes":2684,"success":2684,"duration_ms":647}
{"time":"2025-07-28T22:19:01.858195+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:01.858208+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:01.884254+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":26}
{"time":"2025-07-28T22:19:02.058423+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:02 [akrotiri/XuQmuO84Kd-000025] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3738B in 1.00160875s
{"time":"2025-07-28T22:19:02.25589+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:02.256006+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:02.905407+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":649}
{"time":"2025-07-28T22:19:02.905429+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:02.905435+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:02.92681+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":21}
{"time":"2025-07-28T22:19:02.926839+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25007,"unique_prefixes":2395,"success":2395,"duration_ms":675}
{"time":"2025-07-28T22:19:03.062164+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:03 [akrotiri/XuQmuO84Kd-000027] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3738B in 1.000895792s
{"time":"2025-07-28T22:19:03.470704+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:03.470728+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:03.4707+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:03.561039+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":90}
{"time":"2025-07-28T22:19:03.561108+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:03.575466+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:03 [akrotiri/XuQmuO84Kd-000026] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3740B in 1.564555083s
{"time":"2025-07-28T22:19:03.593318+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:03 [akrotiri/XuQmuO84Kd-000028] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52916 - 200 3740B in 1.000340625s
{"time":"2025-07-28T22:19:03.61064+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":49}
{"time":"2025-07-28T22:19:03.937854+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:03.937872+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:04.007354+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:04.116903+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:04 [akrotiri/XuQmuO84Kd-000029] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3744B in 1.000585208s
{"time":"2025-07-28T22:19:04.39334+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:04.514272+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.81.194.92","peer_asn":"57111"}
{"time":"2025-07-28T22:19:04.617269+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:04 [akrotiri/XuQmuO84Kd-000030] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3750B in 1.001061s
{"time":"2025-07-28T22:19:04.67222+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":734}
{"time":"2025-07-28T22:19:04.672241+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:04.672228+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:04.762751+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":90}
{"time":"2025-07-28T22:19:04.76278+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:04.764372+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:04.765979+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":3}
{"time":"2025-07-28T22:19:04.765992+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:04.779848+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":13}
{"time":"2025-07-28T22:19:04.779883+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25003,"unique_prefixes":2760,"success":2760,"duration_ms":846}
{"time":"2025-07-28T22:19:04.779863+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:04.790998+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:04.831825+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":51}
{"time":"2025-07-28T22:19:04.831834+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:04.833273+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:05.120374+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:05 [akrotiri/XuQmuO84Kd-000031] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3745B in 1.001574958s
{"time":"2025-07-28T22:19:05.307791+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:05.624469+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:05 [akrotiri/XuQmuO84Kd-000032] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3748B in 1.001255541s
{"time":"2025-07-28T22:19:05.957387+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":1125}
{"time":"2025-07-28T22:19:05.95744+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:05.957388+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:05.993975+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":36}
{"time":"2025-07-28T22:19:05.99399+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:05.995935+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:05.997522+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":3}
{"time":"2025-07-28T22:19:05.997535+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:06.005633+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":8}
{"time":"2025-07-28T22:19:06.005649+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":6447,"success":6447,"duration_ms":1223}
{"time":"2025-07-28T22:19:06.00569+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:06.013955+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:06.058347+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":52}
{"time":"2025-07-28T22:19:06.05836+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:06.095545+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:06.139346+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:06 [akrotiri/XuQmuO84Kd-000033] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3742B in 1.001476042s
{"time":"2025-07-28T22:19:06.376969+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"195.208.209.174","peer_asn":"25227"}
{"time":"2025-07-28T22:19:06.631302+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:06 [akrotiri/XuQmuO84Kd-000034] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3745B in 1.001335s
{"time":"2025-07-28T22:19:06.971818+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":913}
{"time":"2025-07-28T22:19:06.971841+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:06.971844+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:06.997143+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":25}
{"time":"2025-07-28T22:19:06.997157+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:06.999139+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:07.003044+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:07.003052+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":5}
{"time":"2025-07-28T22:19:07.003087+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25003,"unique_prefixes":4555,"success":4555,"duration_ms":995}
{"time":"2025-07-28T22:19:07.011185+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:07.042205+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":39}
{"time":"2025-07-28T22:19:07.042246+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:07.143794+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:07 [akrotiri/XuQmuO84Kd-000035] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3742B in 1.001423916s
{"time":"2025-07-28T22:19:07.2758+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:07.896945+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:07.910879+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":868}
{"time":"2025-07-28T22:19:07.910902+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:07.910911+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:07.918682+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":7}
{"time":"2025-07-28T22:19:07.918697+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:07.971136+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":52}
{"time":"2025-07-28T22:19:07.971158+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:07.985082+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":13}
{"time":"2025-07-28T22:19:07.985103+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25011,"unique_prefixes":3758,"success":3758,"duration_ms":980}
{"time":"2025-07-28T22:19:07.998861+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:07.998877+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:08.185013+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:08 [akrotiri/XuQmuO84Kd-000036] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3746B in 1.001581334s
{"time":"2025-07-28T22:19:08.208218+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:08 [akrotiri/XuQmuO84Kd-000037] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3746B in 1.001769209s
{"time":"2025-07-28T22:19:08.380094+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:08.577044+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.249.210.89","peer_asn":"31042"}
{"time":"2025-07-28T22:19:08.65368+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
{"time":"2025-07-28T22:19:08.653706+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
{"time":"2025-07-28T22:19:08.664817+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:08 [akrotiri/XuQmuO84Kd-000038] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52916 - 200 3748B in 1.001547708s
{"time":"2025-07-28T22:19:08.794053+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:09.185878+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:09 [akrotiri/XuQmuO84Kd-000039] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52922 - 200 3753B in 1.000560625s
{"time":"2025-07-28T22:19:09.563887+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:09.563889+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":1564}
{"time":"2025-07-28T22:19:09.563936+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:09.657062+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":93}
{"time":"2025-07-28T22:19:09.657077+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:09.658741+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:09.661207+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":4}
{"time":"2025-07-28T22:19:09.661251+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:09.667519+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:09 [akrotiri/XuQmuO84Kd-000040] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3749B in 1.000375s
{"time":"2025-07-28T22:19:09.668219+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":6}
{"time":"2025-07-28T22:19:09.668232+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:09.668234+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":8887,"success":8887,"duration_ms":1681}
{"time":"2025-07-28T22:19:09.685247+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:09.744598+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":76}
{"time":"2025-07-28T22:19:09.744751+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:10.086808+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":20001031458,"total_messages":114176,"total_bytes":86196921,"total_mb":"82.20","messages_per_sec":"1613.26","bits_per_sec":"9770467","mbps":"9.77","total_dropped":0}
{"time":"2025-07-28T22:19:10.086846+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":113203,"dropped":0,"avg_time":113498,"min_time":0,"max_time":2575248875}
{"time":"2025-07-28T22:19:10.086857+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":113203,"dropped":0,"avg_time":80154,"min_time":0,"max_time":1835761334}
{"time":"2025-07-28T22:19:10.086865+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":3421,"queue_cap":100000,"processed":109781,"dropped":0,"avg_time":140819,"min_time":0,"max_time":2210706750}
{"time":"2025-07-28T22:19:10.086873+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":113203,"dropped":0,"avg_time":1620,"min_time":0,"max_time":2991792}
{"time":"2025-07-28T22:19:10.147065+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:10.186545+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:10 [akrotiri/XuQmuO84Kd-000041] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3747B in 1.001494833s
{"time":"2025-07-28T22:19:10.419238+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8:4::73ab:1","peer_asn":"29611"}
{"time":"2025-07-28T22:19:10.689734+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:10 [akrotiri/XuQmuO84Kd-000042] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3748B in 1.001573458s
{"time":"2025-07-28T22:19:10.958185+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:11.198398+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:19:11 [akrotiri/XuQmuO84Kd-000043] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52917 - 200 3752B in 1.001362583s
{"time":"2025-07-28T22:19:11.700987+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:19:11 [akrotiri/XuQmuO84Kd-000044] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:52915 - 200 3752B in 1.000604584s
{"time":"2025-07-28T22:19:11.848958+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":2104}
{"time":"2025-07-28T22:19:11.848975+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:11.848981+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:11.983957+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":134}
{"time":"2025-07-28T22:19:11.983975+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:643"}
{"time":"2025-07-28T22:19:11.986277+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:11.993259+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:643)","duration_ms":9}
{"time":"2025-07-28T22:19:11.993283+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:265"}
{"time":"2025-07-28T22:19:11.99995+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:265)","duration_ms":6}
{"time":"2025-07-28T22:19:11.999967+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25016,"unique_prefixes":12479,"success":12479,"duration_ms":2329}
{"time":"2025-07-28T22:19:12.000007+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
{"time":"2025-07-28T22:19:12.012355+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:12.03433+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:335)","duration_ms":34}
{"time":"2025-07-28T22:19:12.034343+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
{"time":"2025-07-28T22:19:12.035773+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:335"}
Reference in New Issue View Git Blame Copy Permalink