routewatch/log.txt
sneak 725d04ffa8 Split prefixes table into prefixes_v4 and prefixes_v6
- Create separate tables for IPv4 and IPv6 prefixes in schema.sql
- Update indexes for new prefix tables
- Update getOrCreatePrefix to use appropriate table based on IP version
- Update GetStatsContext to count prefixes from both tables
- Remove ip_version column since it's implicit in the table name
2025-07-28 22:41:42 +02:00

768 lines
152 KiB
Plaintext

[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.042µ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 8.459µ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.125µs
[Fx] BEFORE RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
{"time":"2025-07-28T22:39:20.801897+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:39:20.808372+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:39:22.775552+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"VACUUM","duration":1967135875}
[Fx] RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]]) in 1.97384475s
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New() in 33.5µ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 24.542µ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 116.667µ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 3µs
[Fx] BEFORE RUN provide: go.uber.org/fx.(*App).shutdowner-fm()
[Fx] RUN provide: go.uber.org/fx.(*App).shutdowner-fm() in 3.667µ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 111.167µs
[Fx] RUNNING
{"time":"2025-07-28T22:39:22.776063+02:00","level":"INFO","msg":"Starting RouteWatch","source":"app.go:64","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:39:22.776087+02:00","level":"INFO","msg":"Using batched database handlers for improved performance","source":"app.go:76","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:39:22.778055+02:00","level":"INFO","msg":"Starting HTTP server","source":"server.go:52","func":"server.(*Server).Start","port":"8080"}
2025/07/28 22:39:22 [akrotiri/MlViNiQI02-000001] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3003B in 49.746083ms
2025/07/28 22:39:23 [akrotiri/MlViNiQI02-000002] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3003B in 71.375417ms
2025/07/28 22:39:23 [akrotiri/MlViNiQI02-000003] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3003B in 76.630583ms
{"time":"2025-07-28T22:39:24.46041+02:00","level":"INFO","msg":"Connected to RIS Live stream","source":"streamer.go:421","func":"streamer.(*Streamer).stream"}
2025/07/28 22:39:24 [akrotiri/MlViNiQI02-000004] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3003B in 68.792958ms
{"time":"2025-07-28T22:39:24.781938+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:24.781979+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:24.782021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:24.78667+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:39:24.789547+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":7}
{"time":"2025-07-28T22:39:24.789593+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
2025/07/28 22:39:24 [akrotiri/MlViNiQI02-000005] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 2977B in 53.420791ms
{"time":"2025-07-28T22:39:24.976286+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":186}
{"time":"2025-07-28T22:39:24.976303+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:39:25.030384+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":54}
{"time":"2025-07-28T22:39:25.030402+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:25.030407+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:25.030989+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:25.030998+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":4356,"unique_prefixes":1064,"success":1064,"duration_ms":253}
2025/07/28 22:39:25 [akrotiri/MlViNiQI02-000006] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 2987B in 77.501917ms
2025/07/28 22:39:25 [akrotiri/MlViNiQI02-000007] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3006B in 76.229291ms
{"time":"2025-07-28T22:39:26.170572+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:26.170615+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:26.20595+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":35}
2025/07/28 22:39:26 [akrotiri/MlViNiQI02-000008] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3006B in 58.74925ms
{"time":"2025-07-28T22:39:26.704422+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:39:26.704446+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:39:26.771568+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:26.771855+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:26.876609+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":172}
{"time":"2025-07-28T22:39:26.876627+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:26.876615+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:26.881549+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:39:26.88156+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:26.893271+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":11}
{"time":"2025-07-28T22:39:26.893296+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:26.893891+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:26.893898+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":5664,"success":5664,"duration_ms":200}
2025/07/28 22:39:26 [akrotiri/MlViNiQI02-000009] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3019B in 37.227208ms
2025/07/28 22:39:27 [akrotiri/MlViNiQI02-000010] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3020B in 74.7465ms
{"time":"2025-07-28T22:39:27.942798+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"198.32.160.113","peer_asn":"15547"}
2025/07/28 22:39:28 [akrotiri/MlViNiQI02-000011] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3020B in 70.334958ms
{"time":"2025-07-28T22:39:28.018796+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:28.018811+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:28.034372+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":15}
{"time":"2025-07-28T22:39:28.395919+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:39:28.395948+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:39:28.480006+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":84}
{"time":"2025-07-28T22:39:28.480022+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:28.480027+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
2025/07/28 22:39:28 [akrotiri/MlViNiQI02-000012] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3021B in 59.012459ms
{"time":"2025-07-28T22:39:28.502773+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":22}
{"time":"2025-07-28T22:39:28.50279+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":5618,"success":5618,"duration_ms":118}
{"time":"2025-07-28T22:39:28.543422+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:39:28.759611+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:28.759642+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:28.761777+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:28.779048+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":19}
{"time":"2025-07-28T22:39:28.779079+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:28.784838+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
2025/07/28 22:39:28 [akrotiri/MlViNiQI02-000013] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3020B in 50.967208ms
{"time":"2025-07-28T22:39:29.086433+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
{"time":"2025-07-28T22:39:29.08652+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
2025/07/28 22:39:29 [akrotiri/MlViNiQI02-000014] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3020B in 66.414583ms
{"time":"2025-07-28T22:39:29.793274+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:39:29.793331+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:39:29.857659+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:29.911672+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:29.911667+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":118}
{"time":"2025-07-28T22:39:29.911702+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:29.929525+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":17}
{"time":"2025-07-28T22:39:29.929543+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:29.931084+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:29.931096+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":18526,"unique_prefixes":4052,"success":4052,"duration_ms":152}
2025/07/28 22:39:29 [akrotiri/MlViNiQI02-000015] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3019B in 36.541833ms
2025/07/28 22:39:30 [akrotiri/MlViNiQI02-000016] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3020B in 69.696166ms
{"time":"2025-07-28T22:39:30.773182+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:30.773232+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:30.784787+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":11}
{"time":"2025-07-28T22:39:30.791259+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:30.791271+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:30.806015+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":14}
2025/07/28 22:39:31 [akrotiri/MlViNiQI02-000017] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 65.5515ms
2025/07/28 22:39:31 [akrotiri/MlViNiQI02-000018] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 75.869125ms
{"time":"2025-07-28T22:39:31.788789+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:39:31.788821+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:39:31.896379+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":107}
{"time":"2025-07-28T22:39:31.896396+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:31.896401+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:31.896899+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:31.896909+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":19644,"unique_prefixes":4715,"success":4715,"duration_ms":118}
2025/07/28 22:39:31 [akrotiri/MlViNiQI02-000019] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 40.628417ms
{"time":"2025-07-28T22:39:32.35256+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:32.352611+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:32.382659+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":30}
2025/07/28 22:39:32 [akrotiri/MlViNiQI02-000020] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 52.653042ms
2025/07/28 22:39:33 [akrotiri/MlViNiQI02-000021] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 54.063834ms
{"time":"2025-07-28T22:39:33.50235+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:33.502371+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:33.508725+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":6}
2025/07/28 22:39:33 [akrotiri/MlViNiQI02-000022] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 154.501083ms
{"time":"2025-07-28T22:39:33.782241+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:39:33.782261+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:39:33.807309+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:33.905156+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":122}
{"time":"2025-07-28T22:39:33.905175+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:33.905201+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:33.916472+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":11}
{"time":"2025-07-28T22:39:33.916485+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:33.918014+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:33.918034+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":15567,"unique_prefixes":4589,"success":4589,"duration_ms":139}
2025/07/28 22:39:34 [akrotiri/MlViNiQI02-000023] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3066B in 49.521292ms
{"time":"2025-07-28T22:39:34.461637+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":10001089958,"total_messages":45855,"total_bytes":33475638,"total_mb":"31.92","messages_per_sec":"1384.25","bits_per_sec":"8121572","mbps":"8.12","total_dropped":0}
{"time":"2025-07-28T22:39:34.461691+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":45407,"dropped":0,"avg_time":10159,"min_time":0,"max_time":121844750}
{"time":"2025-07-28T22:39:34.461707+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":45407,"dropped":0,"avg_time":3705,"min_time":0,"max_time":110408625}
{"time":"2025-07-28T22:39:34.461718+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":45407,"dropped":0,"avg_time":13281,"min_time":0,"max_time":200721208}
{"time":"2025-07-28T22:39:34.461728+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":45407,"dropped":0,"avg_time":1692,"min_time":0,"max_time":1248042}
2025/07/28 22:39:34 [akrotiri/MlViNiQI02-000024] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3067B in 60.491125ms
{"time":"2025-07-28T22:39:34.775534+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:34.775549+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:34.792356+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":16}
2025/07/28 22:39:35 [akrotiri/MlViNiQI02-000025] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 71.444042ms
{"time":"2025-07-28T22:39:35.054681+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:de8:4::1:8403:1","peer_asn":"18403"}
2025/07/28 22:39:35 [akrotiri/MlViNiQI02-000026] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 61.154291ms
{"time":"2025-07-28T22:39:35.781509+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:39:35.781524+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:39:35.854247+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":72}
{"time":"2025-07-28T22:39:35.854282+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:35.854287+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:35.855448+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:35.855503+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":24124,"unique_prefixes":3150,"success":3150,"duration_ms":77}
{"time":"2025-07-28T22:39:35.978159+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:35.978175+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:35.983216+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
{"time":"2025-07-28T22:39:36.019158+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:36.019171+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:36.027012+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":7}
2025/07/28 22:39:36 [akrotiri/MlViNiQI02-000027] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 51.919333ms
{"time":"2025-07-28T22:39:36.63892+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"103.200.113.1","peer_asn":"131477"}
{"time":"2025-07-28T22:39:36.658995+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:43f8:6d0::60","peer_asn":"37468"}
{"time":"2025-07-28T22:39:36.748748+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"2400:c3e0::2","peer_asn":"142271"}
2025/07/28 22:39:36 [akrotiri/MlViNiQI02-000028] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 51.366416ms
{"time":"2025-07-28T22:39:36.960935+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:36.960951+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:36.971374+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":10}
2025/07/28 22:39:37 [akrotiri/MlViNiQI02-000029] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 52.202166ms
2025/07/28 22:39:37 [akrotiri/MlViNiQI02-000030] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 62.258375ms
{"time":"2025-07-28T22:39:37.739933+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
{"time":"2025-07-28T22:39:37.743136+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
{"time":"2025-07-28T22:39:37.782506+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:39:37.78252+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:39:38.019151+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":236}
{"time":"2025-07-28T22:39:38.019167+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:38.019171+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:38.027661+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":8}
{"time":"2025-07-28T22:39:38.027676+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20222,"unique_prefixes":4419,"success":4419,"duration_ms":249}
2025/07/28 22:39:38 [akrotiri/MlViNiQI02-000031] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 70.923292ms
{"time":"2025-07-28T22:39:38.132358+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:38.132369+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:38.132489+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:38.138329+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
{"time":"2025-07-28T22:39:38.138342+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:38.148298+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":9}
2025/07/28 22:39:38 [akrotiri/MlViNiQI02-000032] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 59.526333ms
{"time":"2025-07-28T22:39:38.866676+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"196.60.8.60","peer_asn":"37468"}
{"time":"2025-07-28T22:39:39.015235+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:39.015249+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:39.030676+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":15}
2025/07/28 22:39:39 [akrotiri/MlViNiQI02-000033] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 58.552208ms
2025/07/28 22:39:39 [akrotiri/MlViNiQI02-000034] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 50.225625ms
{"time":"2025-07-28T22:39:39.71836+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:39.718387+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:39.72688+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":8}
{"time":"2025-07-28T22:39:39.727299+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:39.727311+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:39.751918+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":24}
{"time":"2025-07-28T22:39:39.785838+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:39:39.785854+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:39:39.896366+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":110}
{"time":"2025-07-28T22:39:39.89638+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:39.896383+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:39.897212+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:39.897221+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":21965,"unique_prefixes":5757,"success":5757,"duration_ms":118}
2025/07/28 22:39:40 [akrotiri/MlViNiQI02-000035] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 42.741ms
{"time":"2025-07-28T22:39:40.50258+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:40.502654+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:40.526839+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":24}
2025/07/28 22:39:40 [akrotiri/MlViNiQI02-000036] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3068B in 76.663083ms
2025/07/28 22:39:41 [akrotiri/MlViNiQI02-000037] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 68.748583ms
2025/07/28 22:39:41 [akrotiri/MlViNiQI02-000038] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 54.168833ms
{"time":"2025-07-28T22:39:41.652083+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:41.6521+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:41.669879+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":17}
{"time":"2025-07-28T22:39:41.786115+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:39:41.78613+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:39:41.82835+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:41.877295+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:41.877295+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":91}
{"time":"2025-07-28T22:39:41.877325+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:41.881571+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:39:41.881592+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:41.883077+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:41.883084+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":16164,"unique_prefixes":3930,"success":3930,"duration_ms":104}
2025/07/28 22:39:42 [akrotiri/MlViNiQI02-000039] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 47.736875ms
2025/07/28 22:39:42 [akrotiri/MlViNiQI02-000040] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 53.620375ms
{"time":"2025-07-28T22:39:42.902304+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:42.902325+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:42.916342+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.81.194.204","peer_asn":"48166"}
{"time":"2025-07-28T22:39:42.923344+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":21}
2025/07/28 22:39:43 [akrotiri/MlViNiQI02-000041] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 53.505958ms
2025/07/28 22:39:43 [akrotiri/MlViNiQI02-000042] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 48.918208ms
{"time":"2025-07-28T22:39:43.785299+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:39:43.785317+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:39:43.875697+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":90}
{"time":"2025-07-28T22:39:43.875711+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:43.875733+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:43.876397+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:43.876405+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":14852,"unique_prefixes":3931,"success":3931,"duration_ms":97}
2025/07/28 22:39:44 [akrotiri/MlViNiQI02-000043] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 37.57375ms
{"time":"2025-07-28T22:39:44.181823+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:44.181841+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:44.202964+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":21}
{"time":"2025-07-28T22:39:44.262435+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:44.26245+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:44.268282+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
{"time":"2025-07-28T22:39:44.46068+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":20000029166,"total_messages":93198,"total_bytes":67585095,"total_mb":"64.45","messages_per_sec":"1875.58","bits_per_sec":"10914914","mbps":"10.91","total_dropped":0}
{"time":"2025-07-28T22:39:44.460771+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":92275,"dropped":0,"avg_time":7066,"min_time":0,"max_time":121844750}
{"time":"2025-07-28T22:39:44.460799+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":92275,"dropped":0,"avg_time":2812,"min_time":0,"max_time":110408625}
{"time":"2025-07-28T22:39:44.460818+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":92275,"dropped":0,"avg_time":11795,"min_time":0,"max_time":200721208}
{"time":"2025-07-28T22:39:44.460835+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":92275,"dropped":0,"avg_time":1445,"min_time":0,"max_time":1391375}
2025/07/28 22:39:44 [akrotiri/MlViNiQI02-000044] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 44.018625ms
{"time":"2025-07-28T22:39:44.956862+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:44.95688+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:44.975225+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":18}
2025/07/28 22:39:45 [akrotiri/MlViNiQI02-000045] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 49.749792ms
2025/07/28 22:39:45 [akrotiri/MlViNiQI02-000046] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 38.289042ms
{"time":"2025-07-28T22:39:45.786844+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:39:45.786875+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:39:45.868742+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":81}
{"time":"2025-07-28T22:39:45.868759+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:45.868763+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:45.869278+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:45.869288+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":15240,"unique_prefixes":3904,"success":3904,"duration_ms":91}
2025/07/28 22:39:46 [akrotiri/MlViNiQI02-000047] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3069B in 45.22725ms
{"time":"2025-07-28T22:39:46.576191+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:46.576207+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:46.590735+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":14}
2025/07/28 22:39:46 [akrotiri/MlViNiQI02-000048] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 72.215084ms
{"time":"2025-07-28T22:39:46.725473+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:46.725502+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:46.732114+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":6}
2025/07/28 22:39:47 [akrotiri/MlViNiQI02-000049] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 71.357292ms
{"time":"2025-07-28T22:39:47.507338+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"193.107.13.3","peer_asn":"47787"}
{"time":"2025-07-28T22:39:47.525016+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:b18:10::3","peer_asn":"47787"}
2025/07/28 22:39:47 [akrotiri/MlViNiQI02-000050] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 55.888792ms
{"time":"2025-07-28T22:39:47.718826+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:47.718847+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:47.739633+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":20}
{"time":"2025-07-28T22:39:47.785622+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:39:47.785647+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:39:47.888229+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":102}
{"time":"2025-07-28T22:39:47.888245+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:47.888254+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:47.889553+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:47.889562+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":23574,"unique_prefixes":5771,"success":5771,"duration_ms":111}
2025/07/28 22:39:48 [akrotiri/MlViNiQI02-000051] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 48.407833ms
{"time":"2025-07-28T22:39:48.49981+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:48.499838+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:48.51947+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":19}
2025/07/28 22:39:48 [akrotiri/MlViNiQI02-000052] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 50.372208ms
{"time":"2025-07-28T22:39:48.611975+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:48.611986+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:48.615562+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:39:49 [akrotiri/MlViNiQI02-000053] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 61.795375ms
2025/07/28 22:39:49 [akrotiri/MlViNiQI02-000054] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 46.04025ms
{"time":"2025-07-28T22:39:49.748126+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:49.748152+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:49.761281+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":13}
{"time":"2025-07-28T22:39:49.785666+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:39:49.785679+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:39:49.867841+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":82}
{"time":"2025-07-28T22:39:49.867856+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:49.867869+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:49.868384+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:49.868391+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":17486,"unique_prefixes":4437,"success":4437,"duration_ms":89}
2025/07/28 22:39:50 [akrotiri/MlViNiQI02-000055] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 51.443625ms
2025/07/28 22:39:50 [akrotiri/MlViNiQI02-000056] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 49.745291ms
{"time":"2025-07-28T22:39:50.777915+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:50.777934+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:50.783096+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
{"time":"2025-07-28T22:39:50.796001+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:50.796013+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:50.811248+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":15}
2025/07/28 22:39:51 [akrotiri/MlViNiQI02-000057] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 43.387625ms
2025/07/28 22:39:51 [akrotiri/MlViNiQI02-000058] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 46.760667ms
{"time":"2025-07-28T22:39:51.781897+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:39:51.781915+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:39:51.851962+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":70}
{"time":"2025-07-28T22:39:51.851977+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:51.851981+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:51.85355+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:51.853561+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":15860,"unique_prefixes":4192,"success":4192,"duration_ms":74}
{"time":"2025-07-28T22:39:52.066447+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:52.066479+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:52.094408+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":27}
2025/07/28 22:39:52 [akrotiri/MlViNiQI02-000059] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 65.970833ms
2025/07/28 22:39:52 [akrotiri/MlViNiQI02-000060] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 57.6925ms
2025/07/28 22:39:53 [akrotiri/MlViNiQI02-000061] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 70.893375ms
{"time":"2025-07-28T22:39:53.489925+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:53.489942+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:53.501124+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:53.511906+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":21}
{"time":"2025-07-28T22:39:53.511919+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:53.516479+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
2025/07/28 22:39:53 [akrotiri/MlViNiQI02-000062] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 63.577ms
{"time":"2025-07-28T22:39:53.783398+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:39:53.783413+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:39:53.959743+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":176}
{"time":"2025-07-28T22:39:53.959758+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:53.959762+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:53.960502+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:53.960511+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":13772,"unique_prefixes":3843,"success":3843,"duration_ms":181}
2025/07/28 22:39:54 [akrotiri/MlViNiQI02-000063] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 62.957292ms
{"time":"2025-07-28T22:39:54.46143+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":30000775500,"total_messages":134144,"total_bytes":97103698,"total_mb":"92.61","messages_per_sec":"2254.79","bits_per_sec":"13100645","mbps":"13.10","total_dropped":0}
{"time":"2025-07-28T22:39:54.46147+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":132771,"dropped":0,"avg_time":6162,"min_time":0,"max_time":121844750}
{"time":"2025-07-28T22:39:54.461481+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":132771,"dropped":0,"avg_time":2235,"min_time":0,"max_time":110408625}
{"time":"2025-07-28T22:39:54.46149+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":132771,"dropped":0,"avg_time":10413,"min_time":0,"max_time":200721208}
{"time":"2025-07-28T22:39:54.461499+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":132771,"dropped":0,"avg_time":1524,"min_time":0,"max_time":3418084}
{"time":"2025-07-28T22:39:54.557021+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:39:54 [akrotiri/MlViNiQI02-000064] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 60.514041ms
{"time":"2025-07-28T22:39:54.990209+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:54.990229+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:55.009862+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":19}
2025/07/28 22:39:55 [akrotiri/MlViNiQI02-000065] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 62.148875ms
{"time":"2025-07-28T22:39:55.60744+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"217.29.66.232","peer_asn":"54104"}
2025/07/28 22:39:55 [akrotiri/MlViNiQI02-000066] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 60.743791ms
{"time":"2025-07-28T22:39:55.78178+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:39:55.781799+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:39:55.911795+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":129}
{"time":"2025-07-28T22:39:55.91181+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:55.911814+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:55.91241+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:55.91242+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":11630,"unique_prefixes":2173,"success":2173,"duration_ms":133}
2025/07/28 22:39:56 [akrotiri/MlViNiQI02-000067] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 71.635917ms
{"time":"2025-07-28T22:39:56.65067+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:56.650682+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:56.667729+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":17}
2025/07/28 22:39:56 [akrotiri/MlViNiQI02-000068] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 66.5605ms
{"time":"2025-07-28T22:39:56.77805+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:56.778068+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:56.782703+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
2025/07/28 22:39:57 [akrotiri/MlViNiQI02-000069] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 72.521583ms
{"time":"2025-07-28T22:39:57.435947+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:39:57 [akrotiri/MlViNiQI02-000070] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 63.024083ms
{"time":"2025-07-28T22:39:57.780354+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:39:57.780366+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:39:57.866994+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":86}
{"time":"2025-07-28T22:39:57.867024+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:57.867028+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:57.867879+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:39:57.867889+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":11999,"unique_prefixes":1521,"success":1521,"duration_ms":89}
2025/07/28 22:39:58 [akrotiri/MlViNiQI02-000071] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 64.941709ms
{"time":"2025-07-28T22:39:58.476985+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:58.477018+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:58.500459+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":23}
2025/07/28 22:39:58 [akrotiri/MlViNiQI02-000072] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 86.141375ms
2025/07/28 22:39:59 [akrotiri/MlViNiQI02-000073] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 58.140042ms
{"time":"2025-07-28T22:39:59.36925+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"80.81.192.113","peer_asn":"35320"}
{"time":"2025-07-28T22:39:59.581772+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:59.581785+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:39:59.591216+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":9}
{"time":"2025-07-28T22:39:59.59776+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:59.597768+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:39:59.601325+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:39:59 [akrotiri/MlViNiQI02-000074] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 49.256ms
{"time":"2025-07-28T22:39:59.781432+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:39:59.781447+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:39:59.892682+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":111}
{"time":"2025-07-28T22:39:59.892696+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:59.89274+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:39:59.893953+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:39:59.893962+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":13027,"unique_prefixes":2438,"success":2438,"duration_ms":115}
2025/07/28 22:40:00 [akrotiri/MlViNiQI02-000075] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 89.521375ms
2025/07/28 22:40:00 [akrotiri/MlViNiQI02-000076] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 79.766042ms
{"time":"2025-07-28T22:40:00.906568+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:00.906586+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:00.920835+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":14}
2025/07/28 22:40:01 [akrotiri/MlViNiQI02-000077] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 61.946833ms
{"time":"2025-07-28T22:40:01.577064+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:01.577089+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:01.57956+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:01.608626+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":31}
{"time":"2025-07-28T22:40:01.60864+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:01.612014+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
{"time":"2025-07-28T22:40:01.78781+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:40:01.787824+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:01 [akrotiri/MlViNiQI02-000078] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 56.311458ms
{"time":"2025-07-28T22:40:01.928351+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":140}
{"time":"2025-07-28T22:40:01.928403+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:01.928411+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:01.928858+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:01.928865+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":22864,"unique_prefixes":10486,"success":10486,"duration_ms":150}
2025/07/28 22:40:02 [akrotiri/MlViNiQI02-000079] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 54.086917ms
2025/07/28 22:40:02 [akrotiri/MlViNiQI02-000080] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 50.947458ms
2025/07/28 22:40:03 [akrotiri/MlViNiQI02-000081] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 63.167083ms
2025/07/28 22:40:03 [akrotiri/MlViNiQI02-000082] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 67.024208ms
{"time":"2025-07-28T22:40:03.760147+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:03.760166+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:03.780763+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:40:03.784421+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":24}
{"time":"2025-07-28T22:40:03.784444+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:40:03.83727+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":52}
{"time":"2025-07-28T22:40:03.837285+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:03.83729+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:03.837658+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:03.837668+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":7687,"unique_prefixes":3888,"success":3888,"duration_ms":59}
{"time":"2025-07-28T22:40:03.94929+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:1042:1","peer_asn":"31042"}
2025/07/28 22:40:04 [akrotiri/MlViNiQI02-000083] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 49.341209ms
{"time":"2025-07-28T22:40:04.424408+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:04.424424+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:04.425709+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:04.433568+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":9}
{"time":"2025-07-28T22:40:04.433588+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:04.438061+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:40:04.4617+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":40001022750,"total_messages":173056,"total_bytes":125533547,"total_mb":"119.72","messages_per_sec":"2421.59","bits_per_sec":"14052855","mbps":"14.05","total_dropped":0}
{"time":"2025-07-28T22:40:04.461712+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":171209,"dropped":0,"avg_time":5725,"min_time":0,"max_time":121844750}
{"time":"2025-07-28T22:40:04.461717+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":171209,"dropped":0,"avg_time":2070,"min_time":0,"max_time":110408625}
{"time":"2025-07-28T22:40:04.461721+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":171209,"dropped":0,"avg_time":8616,"min_time":0,"max_time":200721208}
{"time":"2025-07-28T22:40:04.461724+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":171209,"dropped":0,"avg_time":1451,"min_time":0,"max_time":3418084}
2025/07/28 22:40:04 [akrotiri/MlViNiQI02-000084] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 43.613458ms
{"time":"2025-07-28T22:40:04.734487+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:04.734503+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:04.760142+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":25}
{"time":"2025-07-28T22:40:05.079421+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:40:05.079438+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:40:05.146674+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:05.149619+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:05.192637+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":113}
{"time":"2025-07-28T22:40:05.192646+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:05.192651+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
2025/07/28 22:40:05 [akrotiri/MlViNiQI02-000085] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3083B in 60.715875ms
{"time":"2025-07-28T22:40:05.24191+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":49}
{"time":"2025-07-28T22:40:05.241933+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:05.246974+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":5}
{"time":"2025-07-28T22:40:05.247024+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:05.247628+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:05.247635+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":10929,"success":10929,"duration_ms":179}
2025/07/28 22:40:05 [akrotiri/MlViNiQI02-000086] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 47.413375ms
{"time":"2025-07-28T22:40:05.828442+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:05.828458+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:05.860868+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":32}
{"time":"2025-07-28T22:40:06.485188+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:06.485203+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:06.513087+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":27}
{"time":"2025-07-28T22:40:06.546552+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:06.546565+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:06.54974+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:40:06 [akrotiri/MlViNiQI02-000087] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 50.225583ms
{"time":"2025-07-28T22:40:06.738236+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:40:06.738251+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:06 [akrotiri/MlViNiQI02-000088] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:65302 - 200 3075B in 56.389541ms
{"time":"2025-07-28T22:40:06.935482+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":197}
{"time":"2025-07-28T22:40:06.935499+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:06.935504+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:06.936417+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:06.936428+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":14508,"success":14508,"duration_ms":208}
{"time":"2025-07-28T22:40:07.124624+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:40:07.253307+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:07.253327+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
2025/07/28 22:40:07 [akrotiri/MlViNiQI02-000089] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 73.027417ms
{"time":"2025-07-28T22:40:07.280735+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":27}
2025/07/28 22:40:07 [akrotiri/MlViNiQI02-000090] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 84.159959ms
{"time":"2025-07-28T22:40:07.907198+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:40:07.909589+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:07.909605+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:07.922229+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:08.034679+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:08.034672+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":125}
{"time":"2025-07-28T22:40:08.037413+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":2}
2025/07/28 22:40:08 [akrotiri/MlViNiQI02-000091] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3072B in 53.295292ms
{"time":"2025-07-28T22:40:08.488166+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:40:08.48818+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:40:08.51492+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
2025/07/28 22:40:08 [akrotiri/MlViNiQI02-000092] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3078B in 67.488375ms
{"time":"2025-07-28T22:40:08.990276+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:09.070163+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":581}
{"time":"2025-07-28T22:40:09.07018+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:09.070171+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:09.114004+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":43}
{"time":"2025-07-28T22:40:09.114017+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:09.115318+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:09.116567+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":2}
{"time":"2025-07-28T22:40:09.116575+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:09.117164+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:09.117171+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25040,"unique_prefixes":16890,"success":16890,"duration_ms":648}
{"time":"2025-07-28T22:40:09.117173+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:09.161639+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":44}
2025/07/28 22:40:09 [akrotiri/MlViNiQI02-000093] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3072B in 50.248917ms
{"time":"2025-07-28T22:40:09.637954+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:09.63797+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:09.678593+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":40}
{"time":"2025-07-28T22:40:09.707826+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:40:09.709197+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"}
2025/07/28 22:40:09 [akrotiri/MlViNiQI02-000094] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3072B in 52.173917ms
2025/07/28 22:40:10 [akrotiri/MlViNiQI02-000095] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3072B in 75.290458ms
{"time":"2025-07-28T22:40:10.31413+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:40:10.314148+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:40:10.378001+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:10.381072+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
2025/07/28 22:40:10 [akrotiri/MlViNiQI02-000096] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3081B in 58.477458ms
{"time":"2025-07-28T22:40:10.79421+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:40:10.878974+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:10.878971+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":564}
{"time":"2025-07-28T22:40:10.879003+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:10.881355+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":2}
{"time":"2025-07-28T22:40:10.881366+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:10.923163+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":41}
{"time":"2025-07-28T22:40:10.92317+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:10.924098+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:10.924108+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":16665,"success":16665,"duration_ms":621}
{"time":"2025-07-28T22:40:11.03438+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:11.034392+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:11.076471+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":42}
2025/07/28 22:40:11 [akrotiri/MlViNiQI02-000097] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 51.120459ms
2025/07/28 22:40:11 [akrotiri/MlViNiQI02-000098] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 61.186458ms
{"time":"2025-07-28T22:40:11.963595+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:11.963619+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:11.963624+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:11.999688+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":36}
{"time":"2025-07-28T22:40:11.999701+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:12.003492+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:40:12 [akrotiri/MlViNiQI02-000099] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 54.686875ms
{"time":"2025-07-28T22:40:12.576607+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:40:12.576625+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:12 [akrotiri/MlViNiQI02-000100] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3078B in 59.51025ms
{"time":"2025-07-28T22:40:12.920123+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"193.239.118.249","peer_asn":"41255"}
{"time":"2025-07-28T22:40:12.921324+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":344}
{"time":"2025-07-28T22:40:12.921334+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:12.921338+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:12.922058+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:12.922065+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":10735,"success":10735,"duration_ms":352}
{"time":"2025-07-28T22:40:13.018503+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:13.018515+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:13.036415+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":17}
2025/07/28 22:40:13 [akrotiri/MlViNiQI02-000101] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 63.909792ms
{"time":"2025-07-28T22:40:13.53763+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:13.537648+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:13.538187+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:13.570216+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":32}
{"time":"2025-07-28T22:40:13.570222+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:13.573824+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:40:13 [akrotiri/MlViNiQI02-000102] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 64.549083ms
{"time":"2025-07-28T22:40:14.170257+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:40:14.170276+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:14 [akrotiri/MlViNiQI02-000103] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3078B in 60.765708ms
{"time":"2025-07-28T22:40:14.329592+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:40:14.39592+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":225}
{"time":"2025-07-28T22:40:14.395939+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:14.395943+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:14.396769+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:14.396777+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25000,"unique_prefixes":7109,"success":7109,"duration_ms":243}
{"time":"2025-07-28T22:40:14.46182+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":50001059458,"total_messages":246784,"total_bytes":177274301,"total_mb":"169.06","messages_per_sec":"3115.09","bits_per_sec":"17901810","mbps":"17.90","total_dropped":0}
{"time":"2025-07-28T22:40:14.461837+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":244428,"dropped":0,"avg_time":11010,"min_time":0,"max_time":599767834}
{"time":"2025-07-28T22:40:14.461842+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":244428,"dropped":0,"avg_time":5279,"min_time":0,"max_time":503683625}
{"time":"2025-07-28T22:40:14.461847+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":244428,"dropped":0,"avg_time":15305,"min_time":0,"max_time":649005042}
{"time":"2025-07-28T22:40:14.461852+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":244428,"dropped":0,"avg_time":1330,"min_time":0,"max_time":3418084}
{"time":"2025-07-28T22:40:14.567744+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:14.567763+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:14.607703+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":39}
2025/07/28 22:40:14 [akrotiri/MlViNiQI02-000104] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 68.631459ms
2025/07/28 22:40:15 [akrotiri/MlViNiQI02-000105] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 66.129333ms
{"time":"2025-07-28T22:40:15.782819+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:40:15.782833+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:15 [akrotiri/MlViNiQI02-000106] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 67.377916ms
{"time":"2025-07-28T22:40:15.803533+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:15.819186+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:15.848079+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":65}
{"time":"2025-07-28T22:40:15.848115+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:15.848086+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:15.8586+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":10}
{"time":"2025-07-28T22:40:15.858619+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:15.863311+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:40:15.86332+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:15.864185+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:15.86419+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":12565,"unique_prefixes":3273,"success":3273,"duration_ms":85}
2025/07/28 22:40:16 [akrotiri/MlViNiQI02-000107] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 67.967042ms
{"time":"2025-07-28T22:40:16.40818+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.81.194.92","peer_asn":"57111"}
2025/07/28 22:40:16 [akrotiri/MlViNiQI02-000108] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 54.445167ms
2025/07/28 22:40:17 [akrotiri/MlViNiQI02-000109] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3074B in 44.500875ms
{"time":"2025-07-28T22:40:17.518748+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:17.518764+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:17.52969+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":10}
{"time":"2025-07-28T22:40:17.780379+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:40:17.780394+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:17 [akrotiri/MlViNiQI02-000110] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 60.568167ms
{"time":"2025-07-28T22:40:17.874984+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":94}
{"time":"2025-07-28T22:40:17.874999+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:17.875003+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:17.875537+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:17.875549+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":10605,"unique_prefixes":2035,"success":2035,"duration_ms":97}
2025/07/28 22:40:18 [akrotiri/MlViNiQI02-000111] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 66.786417ms
{"time":"2025-07-28T22:40:18.427974+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T22:40:18.428022+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T22:40:18.777642+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:18.777657+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:18.787767+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":10}
2025/07/28 22:40:18 [akrotiri/MlViNiQI02-000112] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 59.625875ms
{"time":"2025-07-28T22:40:19.030041+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:19.030058+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:19.041664+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":11}
2025/07/28 22:40:19 [akrotiri/MlViNiQI02-000113] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 55.721ms
{"time":"2025-07-28T22:40:19.697892+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:517","func":"streamer.(*Streamer).stream","peer":"2602:fa91:0:cccc::20","peer_asn":"53427"}
{"time":"2025-07-28T22:40:19.780696+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:40:19.78071+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:19 [akrotiri/MlViNiQI02-000114] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 59.532209ms
{"time":"2025-07-28T22:40:19.826404+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":45}
{"time":"2025-07-28T22:40:19.826421+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:19.826426+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:19.827281+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:19.827289+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":11540,"unique_prefixes":2194,"success":2194,"duration_ms":48}
{"time":"2025-07-28T22:40:20.126408+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:20.126428+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:20.139351+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":12}
2025/07/28 22:40:20 [akrotiri/MlViNiQI02-000115] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 71.14925ms
{"time":"2025-07-28T22:40:20.814411+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:20.814426+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:20.815316+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
2025/07/28 22:40:20 [akrotiri/MlViNiQI02-000116] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 54.49675ms
{"time":"2025-07-28T22:40:20.822063+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":7}
{"time":"2025-07-28T22:40:20.82208+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:20.825709+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":3}
2025/07/28 22:40:21 [akrotiri/MlViNiQI02-000117] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 62.613584ms
{"time":"2025-07-28T22:40:21.781668+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:40:21.781711+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:40:21.821294+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:21.839264+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:21.839257+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":57}
{"time":"2025-07-28T22:40:21.839303+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
2025/07/28 22:40:21 [akrotiri/MlViNiQI02-000118] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3080B in 66.549333ms
{"time":"2025-07-28T22:40:21.856622+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":17}
{"time":"2025-07-28T22:40:21.85663+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:21.858739+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":2}
{"time":"2025-07-28T22:40:21.858748+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":16643,"unique_prefixes":3055,"success":3055,"duration_ms":79}
2025/07/28 22:40:22 [akrotiri/MlViNiQI02-000119] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 56.106917ms
{"time":"2025-07-28T22:40:22.777497+02:00","level":"DEBUG","msg":"System stats","source":"cli.go:40","func":"routewatch.logDebugStats","goroutines":25,"alloc_mb":47,"total_alloc_mb":1323,"sys_mb":108,"num_gc":48,"heap_alloc_mb":47,"heap_sys_mb":98,"heap_idle_mb":41,"heap_inuse_mb":56,"heap_released_mb":19,"stack_inuse_mb":1}
2025/07/28 22:40:22 [akrotiri/MlViNiQI02-000120] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 72.129917ms
{"time":"2025-07-28T22:40:22.958252+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:22.958266+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:22.965115+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":6}
{"time":"2025-07-28T22:40:23.192315+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:23.192368+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:23.205493+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":13}
2025/07/28 22:40:23 [akrotiri/MlViNiQI02-000121] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 53.463208ms
{"time":"2025-07-28T22:40:23.781744+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:40:23.781765+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:40:23.814309+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":32}
{"time":"2025-07-28T22:40:23.814324+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:23.814332+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:23.816345+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":2}
{"time":"2025-07-28T22:40:23.816355+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":11382,"unique_prefixes":1917,"success":1917,"duration_ms":37}
2025/07/28 22:40:23 [akrotiri/MlViNiQI02-000122] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 66.205333ms
{"time":"2025-07-28T22:40:24.104918+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"102.67.56.1","peer_asn":"328474"}
2025/07/28 22:40:24 [akrotiri/MlViNiQI02-000123] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 78.253416ms
{"time":"2025-07-28T22:40:24.394727+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:24.394737+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:24.461407+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":66}
{"time":"2025-07-28T22:40:24.461455+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:279","func":"streamer.(*Streamer).logMetrics","uptime":60000661750,"total_messages":285696,"total_bytes":206235023,"total_mb":"196.68","messages_per_sec":"3347.74","bits_per_sec":"19269129","mbps":"19.27","total_dropped":0}
{"time":"2025-07-28T22:40:24.461501+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":282864,"dropped":0,"avg_time":10430,"min_time":0,"max_time":599767834}
{"time":"2025-07-28T22:40:24.461508+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":282864,"dropped":0,"avg_time":4843,"min_time":0,"max_time":503683625}
{"time":"2025-07-28T22:40:24.461512+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:312","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":282864,"dropped":0,"avg_time":13773,"min_time":0,"max_time":649005042}
{"time":"2025-07-28T22:40:24.46152+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":282864,"dropped":0,"avg_time":1348,"min_time":0,"max_time":3418084}
2025/07/28 22:40:24 [akrotiri/MlViNiQI02-000124] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 59.046291ms
2025/07/28 22:40:25 [akrotiri/MlViNiQI02-000125] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 86.920333ms
{"time":"2025-07-28T22:40:25.480373+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:25.480395+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:25.502119+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":21}
{"time":"2025-07-28T22:40:25.785141+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:40:25.785169+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:25 [akrotiri/MlViNiQI02-000126] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 73.257458ms
{"time":"2025-07-28T22:40:25.899401+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:12f8::221:238","peer_asn":"262317"}
{"time":"2025-07-28T22:40:25.900638+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:25.953155+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":167}
{"time":"2025-07-28T22:40:25.953163+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:25.95317+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:25.957201+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:40:25.95721+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:25.957655+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:25.957665+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":13013,"unique_prefixes":2658,"success":2658,"duration_ms":178}
2025/07/28 22:40:26 [akrotiri/MlViNiQI02-000127] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 74.549ms
{"time":"2025-07-28T22:40:26.472944+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:26.472961+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:26.492887+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":19}
2025/07/28 22:40:26 [akrotiri/MlViNiQI02-000128] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 63.915083ms
{"time":"2025-07-28T22:40:27.159908+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:27.159926+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:27.167261+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:27.204351+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":44}
{"time":"2025-07-28T22:40:27.204356+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:27.207276+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":2}
{"time":"2025-07-28T22:40:27.327277+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:40:27.327291+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:27 [akrotiri/MlViNiQI02-000129] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3075B in 63.739291ms
{"time":"2025-07-28T22:40:27.429697+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":102}
{"time":"2025-07-28T22:40:27.429713+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:27.429717+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:27.430238+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":0}
{"time":"2025-07-28T22:40:27.430254+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":25005,"unique_prefixes":5649,"success":5649,"duration_ms":108}
2025/07/28 22:40:27 [akrotiri/MlViNiQI02-000130] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3073B in 70.138084ms
{"time":"2025-07-28T22:40:27.972471+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:27.972488+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:28.004637+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":32}
{"time":"2025-07-28T22:40:28.37354+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:28.373555+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
2025/07/28 22:40:28 [akrotiri/MlViNiQI02-000131] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 56.26025ms
{"time":"2025-07-28T22:40:28.453059+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":79}
{"time":"2025-07-28T22:40:28.58797+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:28.587989+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:684"}
{"time":"2025-07-28T22:40:28.592654+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:684)","duration_ms":4}
{"time":"2025-07-28T22:40:28.793918+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:40:28.793933+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:184"}
2025/07/28 22:40:28 [akrotiri/MlViNiQI02-000132] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:64965 - 200 3076B in 67.380709ms
{"time":"2025-07-28T22:40:29.104967+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:29.120681+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:184)","duration_ms":326}
{"time":"2025-07-28T22:40:29.120691+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:376"}
{"time":"2025-07-28T22:40:29.120693+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:147","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:29.154068+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:376)","duration_ms":33}
{"time":"2025-07-28T22:40:29.154077+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:153","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:291"}
{"time":"2025-07-28T22:40:29.15549+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:165","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:291)","duration_ms":1}
{"time":"2025-07-28T22:40:29.155498+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:232","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":18943,"unique_prefixes":9747,"success":9747,"duration_ms":377}