sneak/routewatch
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
6d46bbad5b
routewatch/log.txt
sneak 6d46bbad5b Fix nil pointer dereference in GetPrefixDistributionContext 
- Use separate variables for IPv4 and IPv6 query results
- Add nil checks before closing rows to prevent panic
- Prevents crash when database queries timeout or fail
2025-07-28 22:04:22 +02:00

1161 lines
233 KiB
Plaintext
Raw Blame History

[Fx] PROVIDE fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] PROVIDE *logger.Logger <= git.eeqj.de/sneak/routewatch/internal/logger.New()
[Fx] PROVIDE *config.Config <= git.eeqj.de/sneak/routewatch/internal/config.New()
[Fx] PROVIDE *metrics.Tracker <= git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] PROVIDE database.Store <= fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
[Fx] PROVIDE *streamer.Streamer <= git.eeqj.de/sneak/routewatch/internal/streamer.New()
[Fx] PROVIDE *server.Server <= git.eeqj.de/sneak/routewatch/internal/server.New()
[Fx] PROVIDE *routewatch.RouteWatch <= git.eeqj.de/sneak/routewatch/internal/routewatch.New()
[Fx] INVOKE git.eeqj.de/sneak/routewatch/internal/routewatch.CLIEntry.func1()
[Fx] BEFORE RUN provide: go.uber.org/fx.New.func1()
[Fx] RUN provide: go.uber.org/fx.New.func1() in 4.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 4.208µ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 3.333µs
[Fx] BEFORE RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]])
{"time":"2025-07-28T22:01:04.984272+02:00","level":"INFO","msg":"Opening database","source":"database.go:61","func":"database.New","path":"/Users/user/Library/Application Support/berlin.sneak.app.routewatch/db.sqlite"}
{"time":"2025-07-28T22:01:05.362826+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"PRAGMA wal_checkpoint(TRUNCATE)","duration":303947625}
{"time":"2025-07-28T22:01:05.363109+02:00","level":"INFO","msg":"Running VACUUM to optimize database (this may take a moment)","source":"database.go:125","func":"database.(*Database).Initialize"}
{"time":"2025-07-28T22:01:21.328362+02:00","level":"DEBUG","msg":"Slow query","source":"slowquery.go:17","func":"database.logSlowQuery","query":"VACUUM","duration":15963139625}
[Fx] RUN provide: fx.Annotate(git.eeqj.de/sneak/routewatch/internal/database.New(), fx.As([[database.Store]]) in 16.347209166s
[Fx] BEFORE RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New()
[Fx] RUN provide: git.eeqj.de/sneak/routewatch/internal/metrics.New() in 823µ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 127.917µ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 523.417µ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 4.875µs
[Fx] BEFORE RUN provide: go.uber.org/fx.(*App).shutdowner-fm()
[Fx] RUN provide: go.uber.org/fx.(*App).shutdowner-fm() in 45.917µ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 300.584µs
[Fx] RUNNING
{"time":"2025-07-28T22:01:21.338349+02:00","level":"INFO","msg":"Starting RouteWatch","source":"app.go:64","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:01:21.338517+02:00","level":"INFO","msg":"Using batched database handlers for improved performance","source":"app.go:76","func":"routewatch.(*RouteWatch).Run"}
{"time":"2025-07-28T22:01:21.341865+02:00","level":"INFO","msg":"Starting HTTP server","source":"server.go:52","func":"server.(*Server).Start","port":"8080"}
2025/07/28 22:01:22 [akrotiri/RUhnevNJMK-000001] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3678B in 624.400792ms
2025/07/28 22:01:23 [akrotiri/RUhnevNJMK-000002] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3678B in 566.482709ms
{"time":"2025-07-28T22:01:23.853564+02:00","level":"INFO","msg":"Connected to RIS Live stream","source":"streamer.go:413","func":"streamer.(*Streamer).stream"}
2025/07/28 22:01:24 [akrotiri/RUhnevNJMK-000003] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3646B in 603.250833ms
{"time":"2025-07-28T22:01:24.346791+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:24.346804+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:24.53404+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:24.555848+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T22:01:24.555887+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T22:01:25.340538+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:25 [akrotiri/RUhnevNJMK-000004] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3693B in 853.076333ms
2025/07/28 22:01:26 [akrotiri/RUhnevNJMK-000005] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3729B in 766.6965ms
{"time":"2025-07-28T22:01:26.757288+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":2410}
{"time":"2025-07-28T22:01:26.757307+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:26.757331+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:27.315883+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2602:fa91:0:cccc::20","peer_asn":"53427"}
2025/07/28 22:01:27 [akrotiri/RUhnevNJMK-000006] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3734B in 959.740709ms
2025/07/28 22:01:27 [akrotiri/RUhnevNJMK-000007] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3734B in 743.030917ms
{"time":"2025-07-28T22:01:27.994679+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":1237}
{"time":"2025-07-28T22:01:27.994737+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:27.996358+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:28.022984+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":28}
{"time":"2025-07-28T22:01:28.022994+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:28.025344+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:28.037666+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:28.037665+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":14}
{"time":"2025-07-28T22:01:28.0377+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":14599,"unique_prefixes":6611,"success":6611,"duration_ms":3695}
{"time":"2025-07-28T22:01:28.046642+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:28.080296+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":42}
{"time":"2025-07-28T22:01:28.080411+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:28.081536+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:28.084673+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":4}
{"time":"2025-07-28T22:01:28.084696+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:28 [akrotiri/RUhnevNJMK-000008] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3753B in 804.725334ms
2025/07/28 22:01:28 [akrotiri/RUhnevNJMK-000009] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3754B in 805.373917ms
2025/07/28 22:01:29 [akrotiri/RUhnevNJMK-000010] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3754B in 700.94275ms
{"time":"2025-07-28T22:01:29.226379+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:29 [akrotiri/RUhnevNJMK-000011] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3757B in 678.106ms
{"time":"2025-07-28T22:01:29.590633+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1505}
{"time":"2025-07-28T22:01:29.590644+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:29.590652+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:29.630883+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":40}
{"time":"2025-07-28T22:01:29.630918+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:29.632535+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:29.634722+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:29.634731+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:29.641724+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":6}
{"time":"2025-07-28T22:01:29.641732+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:29.641737+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":6395,"success":6395,"duration_ms":1602}
{"time":"2025-07-28T22:01:29.657978+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:29.675279+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":33}
{"time":"2025-07-28T22:01:29.675319+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:29.676556+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:29.763831+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"102.67.56.1","peer_asn":"328474"}
2025/07/28 22:01:30 [akrotiri/RUhnevNJMK-000012] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3753B in 920.511291ms
2025/07/28 22:01:30 [akrotiri/RUhnevNJMK-000013] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3753B in 716.350125ms
2025/07/28 22:01:31 [akrotiri/RUhnevNJMK-000014] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 679.880083ms
{"time":"2025-07-28T22:01:31.111051+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:31.111047+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1435}
{"time":"2025-07-28T22:01:31.111112+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:31.510809+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:31.510805+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":399}
{"time":"2025-07-28T22:01:31.512452+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:31 [akrotiri/RUhnevNJMK-000015] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3751B in 676.542666ms
{"time":"2025-07-28T22:01:31.568475+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:31.568473+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":57}
{"time":"2025-07-28T22:01:31.568504+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20015,"unique_prefixes":7993,"success":7993,"duration_ms":1925}
{"time":"2025-07-28T22:01:31.574136+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:31.610023+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":41}
{"time":"2025-07-28T22:01:31.610026+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:31.611202+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:32 [akrotiri/RUhnevNJMK-000016] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 660.744667ms
{"time":"2025-07-28T22:01:32.10543+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:32 [akrotiri/RUhnevNJMK-000017] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3754B in 638.409417ms
{"time":"2025-07-28T22:01:32.541483+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":931}
{"time":"2025-07-28T22:01:32.541499+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:32.541488+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:32.570365+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":28}
{"time":"2025-07-28T22:01:32.570377+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:32.574364+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:32.574371+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:32.579091+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:01:32.579102+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20128,"unique_prefixes":4585,"success":4585,"duration_ms":1009}
{"time":"2025-07-28T22:01:32.585714+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:32.585723+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:32.591847+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:12f8::221:238","peer_asn":"262317"}
{"time":"2025-07-28T22:01:32.906171+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:33 [akrotiri/RUhnevNJMK-000018] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 671.690709ms
2025/07/28 22:01:33 [akrotiri/RUhnevNJMK-000019] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3750B in 659.939125ms
{"time":"2025-07-28T22:01:33.854804+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":10001128792,"total_messages":46592,"total_bytes":34707300,"total_mb":"33.10","messages_per_sec":"489.62","bits_per_sec":"2858426","mbps":"2.86","total_dropped":0}
{"time":"2025-07-28T22:01:33.85483+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":4222,"queue_cap":100000,"processed":41866,"dropped":0,"avg_time":191952,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:01:33.854836+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":46089,"dropped":0,"avg_time":78637,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:01:33.85484+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":18561,"queue_cap":100000,"processed":27527,"dropped":0,"avg_time":298957,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:01:33.854856+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":46089,"dropped":0,"avg_time":1310,"min_time":0,"max_time":447917}
{"time":"2025-07-28T22:01:33.907839+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1322}
{"time":"2025-07-28T22:01:33.907858+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:33.907843+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:34 [akrotiri/RUhnevNJMK-000020] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3752B in 662.324083ms
{"time":"2025-07-28T22:01:34.293497+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:34.293494+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":385}
{"time":"2025-07-28T22:01:34.294759+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:34.311067+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":17}
{"time":"2025-07-28T22:01:34.311097+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20025,"unique_prefixes":7017,"success":7017,"duration_ms":1731}
{"time":"2025-07-28T22:01:34.311075+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:34.316263+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:34.347808+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":36}
{"time":"2025-07-28T22:01:34.347814+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:34 [akrotiri/RUhnevNJMK-000021] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3749B in 672.9005ms
{"time":"2025-07-28T22:01:34.67473+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:35 [akrotiri/RUhnevNJMK-000022] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3754B in 655.746333ms
{"time":"2025-07-28T22:01:35.241005+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:35.241004+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":893}
{"time":"2025-07-28T22:01:35.241035+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:35.24455+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:35.244558+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:35.516258+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":271}
{"time":"2025-07-28T22:01:35.516281+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":5096,"success":5096,"duration_ms":1204}
{"time":"2025-07-28T22:01:35.522156+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:35.522175+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:35 [akrotiri/RUhnevNJMK-000023] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3751B in 656.236625ms
{"time":"2025-07-28T22:01:35.828098+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:36 [akrotiri/RUhnevNJMK-000024] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3752B in 682.476708ms
2025/07/28 22:01:36 [akrotiri/RUhnevNJMK-000025] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3753B in 664.882834ms
{"time":"2025-07-28T22:01:36.668677+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1146}
{"time":"2025-07-28T22:01:36.668701+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:36.668685+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:36.812488+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:37.050778+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:37.050776+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":382}
{"time":"2025-07-28T22:01:37.05198+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:37.067833+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":17}
{"time":"2025-07-28T22:01:37.067849+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20011,"unique_prefixes":5834,"success":5834,"duration_ms":1550}
{"time":"2025-07-28T22:01:37.06784+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:37.071724+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:37.071758+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:37.076639+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:37.113344+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:37.11334+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":41}
2025/07/28 22:01:37 [akrotiri/RUhnevNJMK-000026] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3751B in 684.735958ms
2025/07/28 22:01:37 [akrotiri/RUhnevNJMK-000027] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 677.072292ms
{"time":"2025-07-28T22:01:37.865532+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:38 [akrotiri/RUhnevNJMK-000028] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3753B in 656.84075ms
{"time":"2025-07-28T22:01:38.123549+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:1042:1","peer_asn":"31042"}
{"time":"2025-07-28T22:01:38.201996+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:38.201992+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1088}
{"time":"2025-07-28T22:01:38.202064+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:38.229111+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":27}
{"time":"2025-07-28T22:01:38.229118+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:38.232187+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:01:38.232199+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":10662,"success":10662,"duration_ms":1163}
{"time":"2025-07-28T22:01:38.238932+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:38.23894+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:38 [akrotiri/RUhnevNJMK-000029] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 817.593584ms
{"time":"2025-07-28T22:01:38.883269+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"198.32.160.113","peer_asn":"15547"}
{"time":"2025-07-28T22:01:39.038654+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:39.127914+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:39 [akrotiri/RUhnevNJMK-000030] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3757B in 998.624625ms
2025/07/28 22:01:39 [akrotiri/RUhnevNJMK-000031] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3757B in 813.614125ms
{"time":"2025-07-28T22:01:40.048297+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:40.048293+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1809}
{"time":"2025-07-28T22:01:40.048326+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:01:40 [akrotiri/RUhnevNJMK-000032] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3757B in 664.02575ms
{"time":"2025-07-28T22:01:40.575297+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":526}
{"time":"2025-07-28T22:01:40.575302+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:40.577067+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:40.589974+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:40.589969+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":14}
{"time":"2025-07-28T22:01:40.591949+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:40.596354+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":6}
{"time":"2025-07-28T22:01:40.596365+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20026,"unique_prefixes":7743,"success":7743,"duration_ms":2363}
{"time":"2025-07-28T22:01:40.596433+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:40 [akrotiri/RUhnevNJMK-000033] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3756B in 668.358375ms
{"time":"2025-07-28T22:01:40.611783+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:40.64741+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":51}
{"time":"2025-07-28T22:01:40.64742+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:40.648513+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:40.64944+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:01:40.64945+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:41 [akrotiri/RUhnevNJMK-000034] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3754B in 664.970917ms
{"time":"2025-07-28T22:01:41.43949+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:41 [akrotiri/RUhnevNJMK-000035] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 658.788208ms
{"time":"2025-07-28T22:01:41.928459+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:41.928458+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1278}
{"time":"2025-07-28T22:01:41.92849+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:01:42 [akrotiri/RUhnevNJMK-000036] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3758B in 693.2295ms
{"time":"2025-07-28T22:01:42.369929+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":441}
{"time":"2025-07-28T22:01:42.36993+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:42.371139+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:42.386261+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":16}
{"time":"2025-07-28T22:01:42.386271+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:42.394882+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":8}
{"time":"2025-07-28T22:01:42.394892+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:42.394893+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":12278,"success":12278,"duration_ms":1797}
{"time":"2025-07-28T22:01:42.404314+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:42.428018+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":33}
{"time":"2025-07-28T22:01:42.428029+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:42.429143+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:42 [akrotiri/RUhnevNJMK-000037] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3754B in 688.135833ms
{"time":"2025-07-28T22:01:43.008942+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:43 [akrotiri/RUhnevNJMK-000038] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3757B in 664.126333ms
2025/07/28 22:01:43 [akrotiri/RUhnevNJMK-000039] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 677.257291ms
{"time":"2025-07-28T22:01:43.841036+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:43.841032+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1412}
{"time":"2025-07-28T22:01:43.841062+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:43.853732+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":20000008417,"total_messages":102400,"total_bytes":75578907,"total_mb":"72.08","messages_per_sec":"1127.10","bits_per_sec":"6631323","mbps":"6.63","total_dropped":0}
{"time":"2025-07-28T22:01:43.853746+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":15021,"queue_cap":100000,"processed":86436,"dropped":0,"avg_time":167993,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:01:43.85375+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":3340,"queue_cap":100000,"processed":98117,"dropped":0,"avg_time":70674,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:01:43.853756+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":41353,"queue_cap":100000,"processed":60104,"dropped":0,"avg_time":300199,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:01:43.853759+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":101458,"dropped":0,"avg_time":1315,"min_time":0,"max_time":893750}
{"time":"2025-07-28T22:01:43.881988+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:43.881984+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":40}
{"time":"2025-07-28T22:01:43.883058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:43.885266+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:43.885273+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:43.890424+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":5}
{"time":"2025-07-28T22:01:43.890437+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":10463,"success":10463,"duration_ms":1494}
{"time":"2025-07-28T22:01:43.890438+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:43.897259+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:de8:4::1:8403:1","peer_asn":"18403"}
{"time":"2025-07-28T22:01:43.898879+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:43.920747+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":30}
{"time":"2025-07-28T22:01:43.920757+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:43.922453+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:44 [akrotiri/RUhnevNJMK-000040] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3758B in 831.70825ms
{"time":"2025-07-28T22:01:44.748197+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:44 [akrotiri/RUhnevNJMK-000041] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 911.975042ms
2025/07/28 22:01:45 [akrotiri/RUhnevNJMK-000042] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3762B in 782.325042ms
2025/07/28 22:01:45 [akrotiri/RUhnevNJMK-000043] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 664.596875ms
{"time":"2025-07-28T22:01:45.871246+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:45.871245+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1950}
{"time":"2025-07-28T22:01:45.871281+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:46.118781+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:43f8:6d0::60","peer_asn":"37468"}
2025/07/28 22:01:46 [akrotiri/RUhnevNJMK-000044] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3762B in 700.99625ms
{"time":"2025-07-28T22:01:46.175519+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:46.175516+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":304}
{"time":"2025-07-28T22:01:46.176861+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:46.187445+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":11}
{"time":"2025-07-28T22:01:46.187457+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:46.189629+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:46.197258+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":9}
{"time":"2025-07-28T22:01:46.197267+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:46.19727+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20004,"unique_prefixes":7607,"success":7607,"duration_ms":2305}
{"time":"2025-07-28T22:01:46.208587+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:46.233354+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":36}
{"time":"2025-07-28T22:01:46.233363+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:46.234494+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:46.236774+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:46.236788+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:46.278082+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"80.81.194.190","peer_asn":"31042"}
{"time":"2025-07-28T22:01:46.303317+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"103.200.113.1","peer_asn":"131477"}
2025/07/28 22:01:46 [akrotiri/RUhnevNJMK-000045] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3759B in 731.221208ms
{"time":"2025-07-28T22:01:47.062058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:47 [akrotiri/RUhnevNJMK-000046] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3761B in 713.984792ms
{"time":"2025-07-28T22:01:47.967847+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:01:47 [akrotiri/RUhnevNJMK-000047] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3751B in 1.001478875s
{"time":"2025-07-28T22:01:48.046005+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1809}
{"time":"2025-07-28T22:01:48.046025+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:48.04603+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:48.053493+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:48.053504+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":7}
{"time":"2025-07-28T22:01:48.053524+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20012,"unique_prefixes":13658,"success":13658,"duration_ms":1855}
{"time":"2025-07-28T22:01:48.065728+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:48.098741+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:48.098739+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":45}
{"time":"2025-07-28T22:01:48.104446+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:48.107992+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:48.108543+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":9}
{"time":"2025-07-28T22:01:48.469861+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:01:48 [akrotiri/RUhnevNJMK-000048] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 0B in 1.000097709s
{"time":"2025-07-28T22:01:48.974429+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:01:48 [akrotiri/RUhnevNJMK-000049] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 0B in 1.000212625s
{"time":"2025-07-28T22:01:49.056688+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:49.479411+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:01:49 [akrotiri/RUhnevNJMK-000050] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3752B in 1.001190334s
{"time":"2025-07-28T22:01:49.670884+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:49.670884+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1562}
{"time":"2025-07-28T22:01:49.671005+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:49.758974+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:b18:10::3","peer_asn":"47787"}
2025/07/28 22:01:49 [akrotiri/RUhnevNJMK-000051] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 839.842917ms
{"time":"2025-07-28T22:01:49.998745+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:49.998746+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":327}
{"time":"2025-07-28T22:01:50.00002+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.003567+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":4}
{"time":"2025-07-28T22:01:50.003567+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:50.004983+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.005002+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":1}
{"time":"2025-07-28T22:01:50.005011+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20008,"unique_prefixes":11441,"success":11441,"duration_ms":1949}
{"time":"2025-07-28T22:01:50.017964+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.045446+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.045443+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":40}
{"time":"2025-07-28T22:01:50.046593+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:50 [akrotiri/RUhnevNJMK-000052] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3760B in 774.444042ms
{"time":"2025-07-28T22:01:50.36058+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":315}
{"time":"2025-07-28T22:01:50.360599+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:50.360588+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.465839+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":105}
{"time":"2025-07-28T22:01:50.465851+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:50.466493+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":0}
{"time":"2025-07-28T22:01:50.466502+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":10838,"success":10838,"duration_ms":459}
{"time":"2025-07-28T22:01:50.467202+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.467208+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.48021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.492528+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":25}
{"time":"2025-07-28T22:01:50.492541+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.493767+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.503146+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"196.60.8.60","peer_asn":"37468"}
{"time":"2025-07-28T22:01:50.866708+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":374}
{"time":"2025-07-28T22:01:50.866727+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:50.866719+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.886091+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":19}
{"time":"2025-07-28T22:01:50.886103+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:50.887451+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.890519+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:01:50.890527+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":11181,"success":11181,"duration_ms":422}
{"time":"2025-07-28T22:01:50.890528+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.89911+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.902593+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":12}
{"time":"2025-07-28T22:01:50.902608+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:50.903824+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:50.928769+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:50 [akrotiri/RUhnevNJMK-000053] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 975.599791ms
{"time":"2025-07-28T22:01:51.372775+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":470}
{"time":"2025-07-28T22:01:51.372795+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:51.372799+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:51.376672+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:51.376692+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:01:51.376724+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":9565,"success":9565,"duration_ms":484}
{"time":"2025-07-28T22:01:51.389055+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:51.39203+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:51.392057+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":15}
{"time":"2025-07-28T22:01:51.393754+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:51.396432+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:51.396436+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":4}
2025/07/28 22:01:51 [akrotiri/RUhnevNJMK-000054] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 927.413375ms
2025/07/28 22:01:51 [akrotiri/RUhnevNJMK-000055] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3757B in 819.113583ms
{"time":"2025-07-28T22:01:51.997727+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:51.997727+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":601}
{"time":"2025-07-28T22:01:51.997816+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:52.102453+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":104}
{"time":"2025-07-28T22:01:52.10246+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:52.10359+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:52.107109+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:01:52.107116+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:52.107125+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20004,"unique_prefixes":13111,"success":13111,"duration_ms":728}
{"time":"2025-07-28T22:01:52.120087+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:52.125368+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":18}
{"time":"2025-07-28T22:01:52.125383+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:52 [akrotiri/RUhnevNJMK-000056] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3757B in 764.428833ms
{"time":"2025-07-28T22:01:52.522069+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":396}
{"time":"2025-07-28T22:01:52.522088+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:52.522092+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:52.530873+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":8}
{"time":"2025-07-28T22:01:52.530893+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20008,"unique_prefixes":8300,"success":8300,"duration_ms":421}
{"time":"2025-07-28T22:01:52.536166+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:52.536183+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:52.78679+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:52.981456+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:01:53 [akrotiri/RUhnevNJMK-000057] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 856.153458ms
{"time":"2025-07-28T22:01:53.124064+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":587}
{"time":"2025-07-28T22:01:53.12408+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:53.124084+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:53.323187+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:53.3232+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":199}
{"time":"2025-07-28T22:01:53.323227+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20022,"unique_prefixes":4708,"success":4708,"duration_ms":791}
2025/07/28 22:01:53 [akrotiri/RUhnevNJMK-000058] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 839.594375ms
{"time":"2025-07-28T22:01:53.332114+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:53.340367+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:53.340367+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":17}
{"time":"2025-07-28T22:01:53.344271+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:53.344279+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:01:53.610146+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":265}
{"time":"2025-07-28T22:01:53.610169+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:53.610173+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:53.620842+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":10}
{"time":"2025-07-28T22:01:53.620856+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20003,"unique_prefixes":4890,"success":4890,"duration_ms":295}
{"time":"2025-07-28T22:01:53.627795+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:53.627804+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:53.820517+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:01:53 [akrotiri/RUhnevNJMK-000059] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3758B in 827.989667ms
{"time":"2025-07-28T22:01:53.853994+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":30000201583,"total_messages":164221,"total_bytes":120618255,"total_mb":"115.03","messages_per_sec":"1966.39","bits_per_sec":"11596129","mbps":"11.60","total_dropped":0}
{"time":"2025-07-28T22:01:53.85401+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":774,"queue_cap":100000,"processed":162002,"dropped":0,"avg_time":152896,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:01:53.854016+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":162777,"dropped":0,"avg_time":74576,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:01:53.85402+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":18910,"queue_cap":100000,"processed":143866,"dropped":0,"avg_time":203409,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:01:53.854024+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":162777,"dropped":0,"avg_time":1341,"min_time":0,"max_time":893750}
{"time":"2025-07-28T22:01:54.164784+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8::7942:0:1","peer_asn":"31042"}
{"time":"2025-07-28T22:01:54.268776+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":640}
{"time":"2025-07-28T22:01:54.268792+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:54.268796+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:54.290848+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"80.81.194.204","peer_asn":"48166"}
{"time":"2025-07-28T22:01:54.377264+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":108}
{"time":"2025-07-28T22:01:54.377323+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:54.379603+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":2}
{"time":"2025-07-28T22:01:54.379618+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":6727,"success":6727,"duration_ms":757}
{"time":"2025-07-28T22:01:54.385689+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:54.3857+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:54 [akrotiri/RUhnevNJMK-000060] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3757B in 825.003458ms
{"time":"2025-07-28T22:01:54.620126+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:54.757402+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":371}
{"time":"2025-07-28T22:01:54.75744+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:54.757415+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:54.771937+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":14}
{"time":"2025-07-28T22:01:54.771967+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:54.77592+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:01:54.775934+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20068,"unique_prefixes":4580,"success":4580,"duration_ms":394}
{"time":"2025-07-28T22:01:54.786005+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:54.78602+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:54 [akrotiri/RUhnevNJMK-000061] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3754B in 791.541958ms
{"time":"2025-07-28T22:01:54.819854+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:55.507669+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:01:55 [akrotiri/RUhnevNJMK-000062] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3749B in 1.000674709s
{"time":"2025-07-28T22:01:55.516472+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:55.926886+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:55.926883+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1140}
{"time":"2025-07-28T22:01:55.92691+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:56.010468+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:01:56 [akrotiri/RUhnevNJMK-000063] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3752B in 1.001334417s
{"time":"2025-07-28T22:01:56.132226+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":205}
{"time":"2025-07-28T22:01:56.132246+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:56.142045+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":9}
{"time":"2025-07-28T22:01:56.142053+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:56.143826+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":1}
{"time":"2025-07-28T22:01:56.143836+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":4616,"success":4616,"duration_ms":1366}
{"time":"2025-07-28T22:01:56.150439+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:56.150453+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:56 [akrotiri/RUhnevNJMK-000064] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3758B in 709.048792ms
{"time":"2025-07-28T22:01:56.40149+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:56.461465+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:56.498296+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":347}
{"time":"2025-07-28T22:01:56.498314+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:56.498303+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:56.527365+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:56.527361+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":29}
{"time":"2025-07-28T22:01:56.530229+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:01:56.530242+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:56.531619+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":1}
{"time":"2025-07-28T22:01:56.531628+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20096,"unique_prefixes":4702,"success":4702,"duration_ms":386}
{"time":"2025-07-28T22:01:56.534991+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:56.534999+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:56 [akrotiri/RUhnevNJMK-000065] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 879.606875ms
{"time":"2025-07-28T22:01:57.218639+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":683}
{"time":"2025-07-28T22:01:57.218656+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.21866+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.376563+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":157}
{"time":"2025-07-28T22:01:57.376598+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":2747,"success":2747,"duration_ms":844}
{"time":"2025-07-28T22:01:57.381221+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:57.381245+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:57.484773+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:57.520041+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:01:57 [akrotiri/RUhnevNJMK-000066] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3749B in 1.001433584s
{"time":"2025-07-28T22:01:57.550907+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":169}
{"time":"2025-07-28T22:01:57.550928+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.550918+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:57.568894+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.568907+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":17}
{"time":"2025-07-28T22:01:57.638392+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":69}
{"time":"2025-07-28T22:01:57.638413+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20002,"unique_prefixes":3087,"success":3087,"duration_ms":260}
{"time":"2025-07-28T22:01:57.641763+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:57.641773+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:01:57 [akrotiri/RUhnevNJMK-000067] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3756B in 716.546125ms
{"time":"2025-07-28T22:01:57.903423+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":261}
{"time":"2025-07-28T22:01:57.903441+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.903446+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:57.911246+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":7}
{"time":"2025-07-28T22:01:57.911263+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20001,"unique_prefixes":3234,"success":3234,"duration_ms":272}
{"time":"2025-07-28T22:01:57.917214+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:57.917227+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:58.52962+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:01:58 [akrotiri/RUhnevNJMK-000068] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3746B in 1.00250825s
{"time":"2025-07-28T22:01:58.749637+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:58.795807+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:01:58.795809+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":878}
{"time":"2025-07-28T22:01:58.795909+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:58.909878+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:59.032233+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:01:59 [akrotiri/RUhnevNJMK-000069] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3750B in 1.000747791s
{"time":"2025-07-28T22:01:59.278713+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":482}
{"time":"2025-07-28T22:01:59.27872+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:59.286853+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":8}
{"time":"2025-07-28T22:01:59.28687+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:01:59.286874+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20018,"unique_prefixes":5462,"success":5462,"duration_ms":1374}
{"time":"2025-07-28T22:01:59.293299+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":6}
{"time":"2025-07-28T22:01:59.293401+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:59.293408+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:59.486233+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":192}
{"time":"2025-07-28T22:01:59.486251+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:59.486256+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:59.489588+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:01:59.489601+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20004,"unique_prefixes":3654,"success":3654,"duration_ms":201}
{"time":"2025-07-28T22:01:59.495081+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:59.495092+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:59.536741+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv6 routes: context deadline exceeded"}
2025/07/28 22:01:59 [akrotiri/RUhnevNJMK-000070] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3745B in 1.00385675s
{"time":"2025-07-28T22:01:59.803645+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":308}
{"time":"2025-07-28T22:01:59.803662+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:59.803666+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:01:59.816071+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":12}
{"time":"2025-07-28T22:01:59.816084+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":4612,"success":4612,"duration_ms":325}
{"time":"2025-07-28T22:01:59.820108+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:01:59.82012+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:00.037726+02:00","level":"WARN","msg":"Failed to get live route counts","source":"handlers.go:271","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1","error":"failed to count IPv4 routes: context deadline exceeded"}
2025/07/28 22:02:00 [akrotiri/RUhnevNJMK-000071] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3746B in 1.00245475s
{"time":"2025-07-28T22:02:00.183685+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:00.541692+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:02:00 [akrotiri/RUhnevNJMK-000072] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 0B in 1.000659084s
{"time":"2025-07-28T22:02:00.72946+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:00.729457+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":909}
{"time":"2025-07-28T22:02:00.729508+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:00 [akrotiri/RUhnevNJMK-000073] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3760B in 806.242167ms
{"time":"2025-07-28T22:02:00.962195+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:00.963073+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":233}
{"time":"2025-07-28T22:02:00.963157+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:00.964347+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:00.968086+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:02:00.9681+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":4158,"success":4158,"duration_ms":1151}
{"time":"2025-07-28T22:02:00.968106+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:00.971238+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:00.971246+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:00.972814+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:00.991363+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":20}
{"time":"2025-07-28T22:02:00.991373+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:01.323003+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":331}
{"time":"2025-07-28T22:02:01.323021+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:01.323025+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:01 [akrotiri/RUhnevNJMK-000074] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3758B in 778.859375ms
{"time":"2025-07-28T22:02:01.338148+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":15}
{"time":"2025-07-28T22:02:01.338164+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20012,"unique_prefixes":4922,"success":4922,"duration_ms":369}
{"time":"2025-07-28T22:02:01.694335+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:01.694351+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:01 [akrotiri/RUhnevNJMK-000075] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 746.671542ms
{"time":"2025-07-28T22:02:02.527352+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":832}
{"time":"2025-07-28T22:02:02.527368+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:02.527372+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:02 [akrotiri/RUhnevNJMK-000076] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3758B in 828.2645ms
2025/07/28 22:02:02 [akrotiri/RUhnevNJMK-000077] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 790.838542ms
{"time":"2025-07-28T22:02:02.934567+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":407}
{"time":"2025-07-28T22:02:02.934585+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20364,"unique_prefixes":6483,"success":6483,"duration_ms":1245}
{"time":"2025-07-28T22:02:03.259301+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:03.259317+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:03 [akrotiri/RUhnevNJMK-000078] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3757B in 759.507334ms
{"time":"2025-07-28T22:02:03.333738+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":74}
{"time":"2025-07-28T22:02:03.340439+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:03.340448+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:03.343294+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:03.50122+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"195.208.208.187","peer_asn":"9002"}
{"time":"2025-07-28T22:02:03.85491+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":40001051875,"total_messages":206848,"total_bytes":152904757,"total_mb":"145.82","messages_per_sec":"2447.99","bits_per_sec":"14525967","mbps":"14.53","total_dropped":0}
{"time":"2025-07-28T22:02:03.854966+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":205009,"dropped":0,"avg_time":135299,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:02:03.854971+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":205009,"dropped":0,"avg_time":67917,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:02:03.854975+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":0,"queue_cap":100000,"processed":205009,"dropped":0,"avg_time":186447,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:02:03.854978+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":205009,"dropped":0,"avg_time":1356,"min_time":0,"max_time":893750}
{"time":"2025-07-28T22:02:03.895341+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:03.895356+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:04.006624+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"80.81.194.92","peer_asn":"57111"}
{"time":"2025-07-28T22:02:04.032344+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"217.29.66.232","peer_asn":"54104"}
{"time":"2025-07-28T22:02:04.063156+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:02:04 [akrotiri/RUhnevNJMK-000079] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 0B in 1.000123417s
{"time":"2025-07-28T22:02:04.102976+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"80.249.210.89","peer_asn":"31042"}
{"time":"2025-07-28T22:02:04.194437+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:04 [akrotiri/RUhnevNJMK-000080] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 699.379083ms
{"time":"2025-07-28T22:02:04.54266+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:04 [akrotiri/RUhnevNJMK-000081] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 651.24025ms
2025/07/28 22:02:05 [akrotiri/RUhnevNJMK-000082] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 676.696875ms
{"time":"2025-07-28T22:02:05.417288+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:05.417282+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1521}
{"time":"2025-07-28T22:02:05.417375+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:05.590277+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":172}
{"time":"2025-07-28T22:02:05.590288+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:05.591547+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:05.595741+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":5}
{"time":"2025-07-28T22:02:05.595785+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:05.62215+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":26}
{"time":"2025-07-28T22:02:05.622167+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20002,"unique_prefixes":8129,"success":8129,"duration_ms":1733}
{"time":"2025-07-28T22:02:05.622208+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:05.629494+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:05.706356+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:05.706354+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":84}
{"time":"2025-07-28T22:02:05.707624+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:05 [akrotiri/RUhnevNJMK-000083] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 692.927ms
{"time":"2025-07-28T22:02:06.044518+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:06 [akrotiri/RUhnevNJMK-000084] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 695.475375ms
2025/07/28 22:02:06 [akrotiri/RUhnevNJMK-000085] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 717.744166ms
{"time":"2025-07-28T22:02:06.818676+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"196.60.8.170","peer_asn":"327781"}
{"time":"2025-07-28T22:02:06.985463+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:06.985461+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1279}
{"time":"2025-07-28T22:02:06.985493+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:07.061728+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":76}
{"time":"2025-07-28T22:02:07.061736+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:07.06294+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:07.063785+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:07.063796+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:07.189417+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:07.207738+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":143}
{"time":"2025-07-28T22:02:07.207752+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20194,"unique_prefixes":6736,"success":6736,"duration_ms":1584}
{"time":"2025-07-28T22:02:07.207872+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:07.218064+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:07.28581+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:07.285805+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":77}
{"time":"2025-07-28T22:02:07.287001+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:07.288231+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:07.288241+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:07 [akrotiri/RUhnevNJMK-000086] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3759B in 688.240667ms
2025/07/28 22:02:07 [akrotiri/RUhnevNJMK-000087] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3759B in 793.6585ms
{"time":"2025-07-28T22:02:08.130214+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"80.81.192.113","peer_asn":"35320"}
2025/07/28 22:02:08 [akrotiri/RUhnevNJMK-000088] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3760B in 672.94475ms
{"time":"2025-07-28T22:02:08.4685+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
{"time":"2025-07-28T22:02:08.470292+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"186.211.128.34","peer_asn":"14840"}
2025/07/28 22:02:08 [akrotiri/RUhnevNJMK-000089] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 619.641709ms
{"time":"2025-07-28T22:02:08.809935+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:08.910564+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1622}
{"time":"2025-07-28T22:02:08.91058+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:08.910581+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:09.08868+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:09.088673+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":178}
{"time":"2025-07-28T22:02:09.089874+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:09.091669+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:09.091676+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:09.101102+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":9}
{"time":"2025-07-28T22:02:09.101114+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:09.10112+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":10964,"success":10964,"duration_ms":1892}
{"time":"2025-07-28T22:02:09.111578+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:09.168231+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:09.168228+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":67}
{"time":"2025-07-28T22:02:09.169589+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:09 [akrotiri/RUhnevNJMK-000090] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3759B in 690.310583ms
2025/07/28 22:02:09 [akrotiri/RUhnevNJMK-000091] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3760B in 750.233958ms
2025/07/28 22:02:10 [akrotiri/RUhnevNJMK-000092] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 696.605875ms
{"time":"2025-07-28T22:02:10.815146+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:10.815148+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1646}
{"time":"2025-07-28T22:02:10.815207+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:10 [akrotiri/RUhnevNJMK-000093] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 725.665625ms
{"time":"2025-07-28T22:02:10.934278+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:10.98418+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:10.984178+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":169}
{"time":"2025-07-28T22:02:10.985216+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:11.019069+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":34}
{"time":"2025-07-28T22:02:11.019086+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":11565,"success":11565,"duration_ms":1917}
{"time":"2025-07-28T22:02:11.019073+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:11.022362+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:11.02237+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:11.027253+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:11.071644+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":49}
{"time":"2025-07-28T22:02:11.071653+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:11.072793+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:11 [akrotiri/RUhnevNJMK-000094] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 708.955292ms
2025/07/28 22:02:11 [akrotiri/RUhnevNJMK-000095] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 730.855875ms
{"time":"2025-07-28T22:02:12.396772+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1325}
{"time":"2025-07-28T22:02:12.396791+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:12.396781+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:12 [akrotiri/RUhnevNJMK-000096] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 807.181959ms
{"time":"2025-07-28T22:02:12.558125+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:12.558121+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":161}
{"time":"2025-07-28T22:02:12.559317+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:12.566894+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":8}
{"time":"2025-07-28T22:02:12.5669+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:12.566909+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20003,"unique_prefixes":9513,"success":9513,"duration_ms":1546}
{"time":"2025-07-28T22:02:12.575771+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:12.601533+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":34}
{"time":"2025-07-28T22:02:12.601625+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:12.602844+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:12 [akrotiri/RUhnevNJMK-000097] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 707.405ms
{"time":"2025-07-28T22:02:13.180238+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2400:c3e0::2","peer_asn":"142271"}
{"time":"2025-07-28T22:02:13.185338+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:13 [akrotiri/RUhnevNJMK-000098] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 768.195ms
{"time":"2025-07-28T22:02:13.597484+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
{"time":"2025-07-28T22:02:13.597504+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:12f8::121","peer_asn":"42473"}
2025/07/28 22:02:13 [akrotiri/RUhnevNJMK-000099] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 638.447917ms
{"time":"2025-07-28T22:02:13.854449+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":50000502000,"total_messages":268482,"total_bytes":197322408,"total_mb":"188.18","messages_per_sec":"2941.38","bits_per_sec":"17253481","mbps":"17.25","total_dropped":0}
{"time":"2025-07-28T22:02:13.854471+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":8769,"queue_cap":100000,"processed":257345,"dropped":0,"avg_time":140451,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:02:13.854477+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":2627,"queue_cap":100000,"processed":263487,"dropped":0,"avg_time":62550,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:02:13.854482+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":31077,"queue_cap":100000,"processed":235037,"dropped":0,"avg_time":199546,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:02:13.854486+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":266115,"dropped":0,"avg_time":1363,"min_time":0,"max_time":893750}
{"time":"2025-07-28T22:02:14.145899+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1544}
{"time":"2025-07-28T22:02:14.145918+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:14.145905+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:14 [akrotiri/RUhnevNJMK-000100] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3765B in 689.966125ms
{"time":"2025-07-28T22:02:14.350023+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:14.350018+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":204}
{"time":"2025-07-28T22:02:14.35122+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:14.355148+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":5}
{"time":"2025-07-28T22:02:14.35516+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:14.357295+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":2}
{"time":"2025-07-28T22:02:14.357307+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:14.357308+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":9022,"success":9022,"duration_ms":1789}
{"time":"2025-07-28T22:02:14.364638+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:14.382676+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":25}
{"time":"2025-07-28T22:02:14.382723+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:14.383971+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:14 [akrotiri/RUhnevNJMK-000101] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3760B in 774.580833ms
2025/07/28 22:02:15 [akrotiri/RUhnevNJMK-000102] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3760B in 689.282416ms
{"time":"2025-07-28T22:02:15.337123+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:15 [akrotiri/RUhnevNJMK-000103] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 675.630292ms
{"time":"2025-07-28T22:02:15.867087+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1484}
{"time":"2025-07-28T22:02:15.867151+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:15.867183+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:16.09999+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":232}
{"time":"2025-07-28T22:02:16.099996+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:16.101169+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:16.10524+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":5}
{"time":"2025-07-28T22:02:16.10525+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:16.118463+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":13}
{"time":"2025-07-28T22:02:16.118474+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":7900,"success":7900,"duration_ms":1759}
{"time":"2025-07-28T22:02:16.118479+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:16.125268+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:16.146214+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":27}
{"time":"2025-07-28T22:02:16.146222+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:16.147624+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:16.245692+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"195.208.209.174","peer_asn":"25227"}
2025/07/28 22:02:16 [akrotiri/RUhnevNJMK-000104] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 744.318792ms
2025/07/28 22:02:16 [akrotiri/RUhnevNJMK-000105] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 720.358209ms
{"time":"2025-07-28T22:02:17.095839+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:17.377271+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1231}
{"time":"2025-07-28T22:02:17.377291+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:17.37728+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:17 [akrotiri/RUhnevNJMK-000106] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3765B in 854.610417ms
{"time":"2025-07-28T22:02:18.142328+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:02:18 [akrotiri/RUhnevNJMK-000107] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 0B in 1.001162084s
{"time":"2025-07-28T22:02:18.283532+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":906}
{"time":"2025-07-28T22:02:18.283584+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:18.28622+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:18.293948+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":10}
{"time":"2025-07-28T22:02:18.294034+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:18.306171+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":12}
{"time":"2025-07-28T22:02:18.306201+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20074,"unique_prefixes":7264,"success":7264,"duration_ms":2186}
{"time":"2025-07-28T22:02:18.306248+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:18.31344+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:18.376117+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":69}
{"time":"2025-07-28T22:02:18.376127+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:18.377295+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:18.651618+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:02:18 [akrotiri/RUhnevNJMK-000108] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 0B in 1.000277s
2025/07/28 22:02:18 [akrotiri/RUhnevNJMK-000109] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 829.337292ms
{"time":"2025-07-28T22:02:19.069595+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":693}
{"time":"2025-07-28T22:02:19.069616+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:19.069603+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:19.16855+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":98}
{"time":"2025-07-28T22:02:19.168572+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:19.169732+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:19.175017+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":6}
{"time":"2025-07-28T22:02:19.175033+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20081,"unique_prefixes":4204,"success":4204,"duration_ms":867}
{"time":"2025-07-28T22:02:19.175051+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:19.185858+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:19.21954+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":44}
{"time":"2025-07-28T22:02:19.219597+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:19.377788+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:19 [akrotiri/RUhnevNJMK-000110] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3761B in 814.847958ms
2025/07/28 22:02:19 [akrotiri/RUhnevNJMK-000111] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 719.801209ms
{"time":"2025-07-28T22:02:19.990014+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:20.050033+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":830}
{"time":"2025-07-28T22:02:20.050044+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:20.050049+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:20.132782+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":82}
{"time":"2025-07-28T22:02:20.132799+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:20.185378+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":52}
{"time":"2025-07-28T22:02:20.185389+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:20.188867+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:02:20.188882+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20002,"unique_prefixes":5380,"success":5380,"duration_ms":1012}
{"time":"2025-07-28T22:02:20.193335+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:20.193347+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:20 [akrotiri/RUhnevNJMK-000112] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3759B in 794.168125ms
{"time":"2025-07-28T22:02:20.735624+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:20.736657+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8:4::73ab:1","peer_asn":"29611"}
{"time":"2025-07-28T22:02:20.829699+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":636}
{"time":"2025-07-28T22:02:20.829708+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:20.829745+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:20 [akrotiri/RUhnevNJMK-000113] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3760B in 692.779375ms
{"time":"2025-07-28T22:02:20.901859+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
{"time":"2025-07-28T22:02:20.901886+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8::8b0e:0:1","peer_asn":"35598"}
{"time":"2025-07-28T22:02:20.904412+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:20.975775+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":146}
{"time":"2025-07-28T22:02:20.975797+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:20.98256+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":6}
{"time":"2025-07-28T22:02:20.98258+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20027,"unique_prefixes":3840,"success":3840,"duration_ms":792}
{"time":"2025-07-28T22:02:20.98259+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:20.987028+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":4}
{"time":"2025-07-28T22:02:20.989719+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:20.989727+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:21.164791+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"193.239.118.249","peer_asn":"41255"}
{"time":"2025-07-28T22:02:21.339342+02:00","level":"DEBUG","msg":"System stats","source":"cli.go:40","func":"routewatch.logDebugStats","goroutines":35,"alloc_mb":98,"total_alloc_mb":1793,"sys_mb":207,"num_gc":42,"heap_alloc_mb":98,"heap_sys_mb":192,"heap_idle_mb":68,"heap_inuse_mb":124,"heap_released_mb":29,"stack_inuse_mb":3}
2025/07/28 22:02:21 [akrotiri/RUhnevNJMK-000114] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3758B in 754.739875ms
{"time":"2025-07-28T22:02:21.81308+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":823}
{"time":"2025-07-28T22:02:21.813098+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:21.813102+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:21.9152+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":102}
{"time":"2025-07-28T22:02:21.915219+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20013,"unique_prefixes":5695,"success":5695,"duration_ms":930}
{"time":"2025-07-28T22:02:21.923164+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:21.923177+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:21.993527+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:22 [akrotiri/RUhnevNJMK-000116] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3760B in 708.570208ms
2025/07/28 22:02:22 [akrotiri/RUhnevNJMK-000115] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3760B in 798.812542ms
{"time":"2025-07-28T22:02:22.824677+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:22 [akrotiri/RUhnevNJMK-000117] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58143 - 200 3763B in 700.42575ms
{"time":"2025-07-28T22:02:23.125161+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1201}
{"time":"2025-07-28T22:02:23.12518+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:23.125164+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:23.255459+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":130}
{"time":"2025-07-28T22:02:23.255543+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:23.256718+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:23.260601+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":5}
{"time":"2025-07-28T22:02:23.260638+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:23.294896+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":34}
{"time":"2025-07-28T22:02:23.294913+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":9024,"success":9024,"duration_ms":1378}
{"time":"2025-07-28T22:02:23.294953+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:23.302047+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:23.349207+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":54}
{"time":"2025-07-28T22:02:23.34922+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:23 [akrotiri/RUhnevNJMK-000118] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3758B in 746.88625ms
{"time":"2025-07-28T22:02:23.854906+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":60000917708,"total_messages":320512,"total_bytes":234264434,"total_mb":"223.41","messages_per_sec":"3258.53","bits_per_sec":"19099531","mbps":"19.10","total_dropped":0}
{"time":"2025-07-28T22:02:23.85493+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":0,"queue_cap":100000,"processed":317647,"dropped":0,"avg_time":140270,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:02:23.854936+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":317647,"dropped":0,"avg_time":65815,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:02:23.85494+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":35927,"queue_cap":100000,"processed":281719,"dropped":0,"avg_time":204549,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:02:23.854943+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":317647,"dropped":0,"avg_time":1398,"min_time":0,"max_time":893750}
2025/07/28 22:02:23 [akrotiri/RUhnevNJMK-000119] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3756B in 692.845583ms
{"time":"2025-07-28T22:02:24.096686+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:24.275413+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":926}
{"time":"2025-07-28T22:02:24.275431+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:24.275468+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:24.40062+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":125}
{"time":"2025-07-28T22:02:24.40063+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:24.404416+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:02:24.40443+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":6814,"success":6814,"duration_ms":1108}
{"time":"2025-07-28T22:02:24.409663+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:24.409673+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:24 [akrotiri/RUhnevNJMK-000120] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3759B in 813.489125ms
2025/07/28 22:02:24 [akrotiri/RUhnevNJMK-000121] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3759B in 678.516875ms
{"time":"2025-07-28T22:02:25.072382+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:25.075156+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:25.251803+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:25.251801+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":842}
{"time":"2025-07-28T22:02:25.251894+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:25.379433+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":127}
{"time":"2025-07-28T22:02:25.379445+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:25.383072+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:25.383084+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:25.386449+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":3}
{"time":"2025-07-28T22:02:25.386461+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20081,"unique_prefixes":5665,"success":5665,"duration_ms":981}
{"time":"2025-07-28T22:02:25.390267+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:25.390276+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:25 [akrotiri/RUhnevNJMK-000122] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3759B in 813.866875ms
2025/07/28 22:02:25 [akrotiri/RUhnevNJMK-000123] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3759B in 694.576959ms
{"time":"2025-07-28T22:02:26.00622+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":615}
{"time":"2025-07-28T22:02:26.006237+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:26.006241+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:26.025971+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":19}
{"time":"2025-07-28T22:02:26.025987+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":3452,"success":3452,"duration_ms":638}
{"time":"2025-07-28T22:02:26.031698+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:26.031707+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:26.32688+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:26 [akrotiri/RUhnevNJMK-000124] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 775.815208ms
2025/07/28 22:02:26 [akrotiri/RUhnevNJMK-000125] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 688.321167ms
{"time":"2025-07-28T22:02:26.985101+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:26.985096+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":953}
{"time":"2025-07-28T22:02:26.985216+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:27.018409+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":33}
{"time":"2025-07-28T22:02:27.018424+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:27.022903+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:02:27.022914+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20312,"unique_prefixes":6472,"success":6472,"duration_ms":996}
{"time":"2025-07-28T22:02:27.02945+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:27.029459+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:27.304286+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"193.107.13.3","peer_asn":"47787"}
{"time":"2025-07-28T22:02:27.362916+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:27.363303+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:27 [akrotiri/RUhnevNJMK-000126] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 738.491542ms
{"time":"2025-07-28T22:02:27.630463+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
{"time":"2025-07-28T22:02:27.630505+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:5598:1","peer_asn":"35598"}
2025/07/28 22:02:27 [akrotiri/RUhnevNJMK-000127] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3765B in 685.237542ms
{"time":"2025-07-28T22:02:28.025876+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":996}
{"time":"2025-07-28T22:02:28.0259+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:28.025882+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:28.129253+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":103}
{"time":"2025-07-28T22:02:28.129269+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:28.132555+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:28.132566+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:28.199832+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":67}
{"time":"2025-07-28T22:02:28.199848+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20083,"unique_prefixes":8328,"success":8328,"duration_ms":1176}
{"time":"2025-07-28T22:02:28.208629+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:28.208644+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:28.411152+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:28 [akrotiri/RUhnevNJMK-000128] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 760.79625ms
2025/07/28 22:02:28 [akrotiri/RUhnevNJMK-000129] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 717.950541ms
{"time":"2025-07-28T22:02:29.028955+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:29 [akrotiri/RUhnevNJMK-000130] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3765B in 670.043167ms
{"time":"2025-07-28T22:02:29.40823+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:29.408224+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1199}
{"time":"2025-07-28T22:02:29.408301+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:29.452313+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":44}
{"time":"2025-07-28T22:02:29.452327+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:29.453511+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:29.455314+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:29.455327+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:29.463001+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":7}
{"time":"2025-07-28T22:02:29.463008+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:29.463015+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20005,"unique_prefixes":10039,"success":10039,"duration_ms":1262}
{"time":"2025-07-28T22:02:29.472385+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:29.517613+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:29.517613+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":54}
{"time":"2025-07-28T22:02:29.626326+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"2602:fa91:0:cccc::20","peer_asn":"53427"}
{"time":"2025-07-28T22:02:29.853958+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:29 [akrotiri/RUhnevNJMK-000131] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 722.559458ms
2025/07/28 22:02:30 [akrotiri/RUhnevNJMK-000132] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 725.408916ms
{"time":"2025-07-28T22:02:30.539641+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:30.916055+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1398}
{"time":"2025-07-28T22:02:30.916073+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:30.916073+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:31 [akrotiri/RUhnevNJMK-000133] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 844.985791ms
{"time":"2025-07-28T22:02:31.079929+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":163}
{"time":"2025-07-28T22:02:31.079934+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:31.081106+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:31.082394+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:31.082405+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:31.086892+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":4}
{"time":"2025-07-28T22:02:31.0869+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:31.086904+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20085,"unique_prefixes":10164,"success":10164,"duration_ms":1622}
{"time":"2025-07-28T22:02:31.09533+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:31.136525+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:31.136538+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":49}
{"time":"2025-07-28T22:02:31.330349+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:31 [akrotiri/RUhnevNJMK-000134] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 843.047166ms
2025/07/28 22:02:31 [akrotiri/RUhnevNJMK-000135] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 696.199375ms
{"time":"2025-07-28T22:02:31.956921+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:32.395042+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1258}
{"time":"2025-07-28T22:02:32.395073+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:32.395049+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:32 [akrotiri/RUhnevNJMK-000136] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 748.732333ms
{"time":"2025-07-28T22:02:32.560364+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":165}
{"time":"2025-07-28T22:02:32.560375+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:32.561897+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:32.563374+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:32.563408+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:32.575871+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":12}
{"time":"2025-07-28T22:02:32.5759+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20002,"unique_prefixes":8098,"success":8098,"duration_ms":1487}
{"time":"2025-07-28T22:02:32.575887+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:32.587886+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:32.63889+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":62}
{"time":"2025-07-28T22:02:32.638901+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:32.749307+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:33 [akrotiri/RUhnevNJMK-000137] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 909.860875ms
2025/07/28 22:02:33 [akrotiri/RUhnevNJMK-000138] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 733.938333ms
{"time":"2025-07-28T22:02:33.533377+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:33.682562+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1043}
{"time":"2025-07-28T22:02:33.682577+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:33.682581+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:33.781885+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"102.67.56.1","peer_asn":"328474"}
{"time":"2025-07-28T22:02:33.810403+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:33.810405+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":127}
{"time":"2025-07-28T22:02:33.810484+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20008,"unique_prefixes":8821,"success":8821,"duration_ms":1233}
{"time":"2025-07-28T22:02:33.820477+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:33.854059+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":70000008875,"total_messages":379904,"total_bytes":276608958,"total_mb":"263.79","messages_per_sec":"3549.48","bits_per_sec":"20607761","mbps":"20.61","total_dropped":0}
{"time":"2025-07-28T22:02:33.854082+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":7507,"queue_cap":100000,"processed":369056,"dropped":0,"avg_time":136381,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:02:33.854094+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":3076,"queue_cap":100000,"processed":373487,"dropped":0,"avg_time":63116,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:02:33.854098+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":46260,"queue_cap":100000,"processed":330303,"dropped":0,"avg_time":206289,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:02:33.854102+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":376564,"dropped":0,"avg_time":1390,"min_time":0,"max_time":893750}
{"time":"2025-07-28T22:02:33.875217+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:33.875218+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":64}
{"time":"2025-07-28T22:02:33.87645+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:33.878297+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:33.878299+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
2025/07/28 22:02:33 [akrotiri/RUhnevNJMK-000139] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 793.000541ms
2025/07/28 22:02:34 [akrotiri/RUhnevNJMK-000140] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 837.306833ms
2025/07/28 22:02:34 [akrotiri/RUhnevNJMK-000141] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3762B in 703.82025ms
{"time":"2025-07-28T22:02:34.909427+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:34.909427+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1031}
{"time":"2025-07-28T22:02:34.909509+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:34.926855+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:12f8::221:238","peer_asn":"262317"}
{"time":"2025-07-28T22:02:35.044223+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":134}
{"time":"2025-07-28T22:02:35.044233+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:35.045434+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:35.051495+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":7}
{"time":"2025-07-28T22:02:35.051508+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20391,"unique_prefixes":6464,"success":6464,"duration_ms":1239}
{"time":"2025-07-28T22:02:35.051522+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:35.058036+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:35.10469+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":53}
{"time":"2025-07-28T22:02:35.104698+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:35.138504+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:35.402151+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:35 [akrotiri/RUhnevNJMK-000142] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 773.275625ms
2025/07/28 22:02:35 [akrotiri/RUhnevNJMK-000143] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3767B in 698.89025ms
{"time":"2025-07-28T22:02:35.985033+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":880}
{"time":"2025-07-28T22:02:35.985056+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:35.985042+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:35.987733+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":2}
{"time":"2025-07-28T22:02:35.987744+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:36.023119+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":35}
{"time":"2025-07-28T22:02:36.023131+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:36.037054+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":13}
{"time":"2025-07-28T22:02:36.037068+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":7637,"success":7637,"duration_ms":984}
{"time":"2025-07-28T22:02:36.044981+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:36.044992+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:36.514029+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:36 [akrotiri/RUhnevNJMK-000144] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3762B in 800.69575ms
{"time":"2025-07-28T22:02:36.925546+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:37 [akrotiri/RUhnevNJMK-000145] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3766B in 844.402ms
{"time":"2025-07-28T22:02:37.443264+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1398}
{"time":"2025-07-28T22:02:37.443281+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:37.443306+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:37.59141+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":148}
{"time":"2025-07-28T22:02:37.591422+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:37.592849+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:37.597874+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":6}
{"time":"2025-07-28T22:02:37.597887+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:37.606465+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":8}
{"time":"2025-07-28T22:02:37.606477+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:37.606481+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":10163,"success":10163,"duration_ms":1568}
{"time":"2025-07-28T22:02:37.615618+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:37.683969+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:37.683965+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":77}
2025/07/28 22:02:37 [akrotiri/RUhnevNJMK-000146] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 783.588542ms
{"time":"2025-07-28T22:02:37.739874+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:37 [akrotiri/RUhnevNJMK-000147] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3763B in 711.794ms
2025/07/28 22:02:38 [akrotiri/RUhnevNJMK-000148] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 798.138125ms
2025/07/28 22:02:38 [akrotiri/RUhnevNJMK-000149] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 746.51125ms
{"time":"2025-07-28T22:02:39.009493+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:39.111468+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:39.111463+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1427}
{"time":"2025-07-28T22:02:39.111544+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:39.26903+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":157}
{"time":"2025-07-28T22:02:39.269098+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:39.270493+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:39.280177+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":11}
{"time":"2025-07-28T22:02:39.280189+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:39.30113+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":20}
{"time":"2025-07-28T22:02:39.301137+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:39.301153+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20009,"unique_prefixes":9103,"success":9103,"duration_ms":1693}
{"time":"2025-07-28T22:02:39.312847+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:39.342309+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":41}
{"time":"2025-07-28T22:02:39.342337+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
2025/07/28 22:02:39 [akrotiri/RUhnevNJMK-000150] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3761B in 725.073583ms
{"time":"2025-07-28T22:02:39.582433+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:39 [akrotiri/RUhnevNJMK-000151] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 727.854291ms
2025/07/28 22:02:40 [akrotiri/RUhnevNJMK-000152] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 671.548042ms
{"time":"2025-07-28T22:02:40.491044+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:40.782978+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:7f8:1::a503:1042:1","peer_asn":"31042"}
2025/07/28 22:02:40 [akrotiri/RUhnevNJMK-000153] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3767B in 711.36175ms
{"time":"2025-07-28T22:02:41.095104+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1752}
{"time":"2025-07-28T22:02:41.095118+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:41.095122+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:41.300716+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:41.300746+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":205}
{"time":"2025-07-28T22:02:41.30229+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:41.306222+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":5}
{"time":"2025-07-28T22:02:41.306249+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:41.319617+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":13}
{"time":"2025-07-28T22:02:41.319661+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":13074,"success":13074,"duration_ms":2017}
{"time":"2025-07-28T22:02:41.319656+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:41.331607+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:41.394339+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":74}
{"time":"2025-07-28T22:02:41.394383+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:41.397175+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:41 [akrotiri/RUhnevNJMK-000154] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3763B in 734.252375ms
{"time":"2025-07-28T22:02:42.005608+02:00","level":"WARN","msg":"BGP notification","source":"streamer.go:509","func":"streamer.(*Streamer).stream","peer":"198.32.160.113","peer_asn":"15547"}
2025/07/28 22:02:42 [akrotiri/RUhnevNJMK-000155] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 766.4015ms
{"time":"2025-07-28T22:02:42.21861+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:42 [akrotiri/RUhnevNJMK-000156] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3767B in 740.036666ms
2025/07/28 22:02:42 [akrotiri/RUhnevNJMK-000157] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3768B in 689.262625ms
{"time":"2025-07-28T22:02:42.990777+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:42.990769+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1596}
{"time":"2025-07-28T22:02:42.990857+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:43.020875+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":30}
{"time":"2025-07-28T22:02:43.020888+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:43.021961+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:43.023905+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":3}
{"time":"2025-07-28T22:02:43.02392+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:43.029445+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":5}
{"time":"2025-07-28T22:02:43.029456+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20000,"unique_prefixes":9684,"success":9684,"duration_ms":1707}
{"time":"2025-07-28T22:02:43.029456+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:43.040738+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:43.226642+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":197}
{"time":"2025-07-28T22:02:43.226649+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:43.227774+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:43 [akrotiri/RUhnevNJMK-000158] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 696.743167ms
{"time":"2025-07-28T22:02:43.854213+02:00","level":"INFO","msg":"Stream statistics","source":"streamer.go:271","func":"streamer.(*Streamer).logMetrics","uptime":80000102792,"total_messages":435712,"total_bytes":317323689,"total_mb":"302.62","messages_per_sec":"3951.39","bits_per_sec":"22934695","mbps":"22.93","total_dropped":0}
{"time":"2025-07-28T22:02:43.854236+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.ASHandler","index":0,"queue_len":5218,"queue_cap":100000,"processed":426676,"dropped":0,"avg_time":139988,"min_time":0,"max_time":3461305541}
{"time":"2025-07-28T22:02:43.854242+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeerHandler","index":1,"queue_len":0,"queue_cap":100000,"processed":431895,"dropped":0,"avg_time":63316,"min_time":0,"max_time":2677144500}
{"time":"2025-07-28T22:02:43.854246+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PrefixHandler","index":2,"queue_len":56656,"queue_cap":100000,"processed":375238,"dropped":0,"avg_time":206146,"min_time":0,"max_time":3687716542}
{"time":"2025-07-28T22:02:43.854261+02:00","level":"INFO","msg":"Handler statistics","source":"streamer.go:304","func":"streamer.(*Streamer).logMetrics","handler":"*routewatch.PeeringHandler","index":3,"queue_len":0,"queue_cap":100000,"processed":431895,"dropped":0,"avg_time":1390,"min_time":0,"max_time":912250}
2025/07/28 22:02:43 [akrotiri/RUhnevNJMK-000159] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3764B in 703.21525ms
2025/07/28 22:02:44 [akrotiri/RUhnevNJMK-000160] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 651.367167ms
{"time":"2025-07-28T22:02:44.543673+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:45 [akrotiri/RUhnevNJMK-000161] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3767B in 760.279792ms
{"time":"2025-07-28T22:02:45.323885+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:45.323882+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":2097}
{"time":"2025-07-28T22:02:45.323913+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
2025/07/28 22:02:45 [akrotiri/RUhnevNJMK-000162] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3768B in 657.70675ms
{"time":"2025-07-28T22:02:45.594589+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
{"time":"2025-07-28T22:02:45.594587+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":270}
{"time":"2025-07-28T22:02:45.595844+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:45.599364+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpdatePeerBatch (database.go:640)","duration_ms":4}
{"time":"2025-07-28T22:02:45.599381+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:45.606436+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"DeleteLiveRouteBatch (database.go:262)","duration_ms":7}
{"time":"2025-07-28T22:02:45.606443+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:45.60645+02:00","level":"DEBUG","msg":"Flushed prefix batch","source":"prefixhandler.go:223","func":"routewatch.(*PrefixHandler).flushBatchLocked","batch_size":20190,"unique_prefixes":13593,"success":13593,"duration_ms":2575}
{"time":"2025-07-28T22:02:45.619036+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:45.636371+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"GetOrCreateASNBatch (database.go:332)","duration_ms":29}
{"time":"2025-07-28T22:02:45.636478+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"UpsertLiveRouteBatch","caller":"database.go:181"}
{"time":"2025-07-28T22:02:45.6379+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
2025/07/28 22:02:46 [akrotiri/RUhnevNJMK-000163] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3761B in 814.492334ms
{"time":"2025-07-28T22:02:46.236652+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"UpdatePeerBatch","caller":"database.go:640"}
2025/07/28 22:02:46 [akrotiri/RUhnevNJMK-000164] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3764B in 739.1915ms
2025/07/28 22:02:47 [akrotiri/RUhnevNJMK-000165] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 3765B in 751.214792ms
2025/07/28 22:02:47 [akrotiri/RUhnevNJMK-000166] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58144 - 200 3765B in 638.575917ms
{"time":"2025-07-28T22:02:47.492969+02:00","level":"DEBUG","msg":"Database lock released","source":"database.go:162","func":"database.(*Database).unlock","held_by":"UpsertLiveRouteBatch (database.go:181)","duration_ms":1856}
{"time":"2025-07-28T22:02:47.492977+02:00","level":"DEBUG","msg":"Database lock acquired","source":"database.go:150","func":"database.(*Database).lock","operation":"GetOrCreateASNBatch","caller":"database.go:332"}
{"time":"2025-07-28T22:02:47.492986+02:00","level":"DEBUG","msg":"Acquiring database lock","source":"database.go:144","func":"database.(*Database).lock","operation":"DeleteLiveRouteBatch","caller":"database.go:262"}
{"time":"2025-07-28T22:02:48.225361+02:00","level":"INFO","msg":"BGP session opened","source":"streamer.go:501","func":"streamer.(*Streamer).stream","peer":"2001:de8:4::1:8403:1","peer_asn":"18403"}
{"time":"2025-07-28T22:02:48.265211+02:00","level":"ERROR","msg":"Database stats timeout","source":"handlers.go:249","func":"server.(*Server).setupRoutes.func1.(*Server).handleStats.1"}
2025/07/28 22:02:48 [akrotiri/RUhnevNJMK-000167] "GET http://127.0.0.1:8080/api/v1/stats HTTP/1.1" from 127.0.0.1:58141 - 200 0B in 1.0000955s
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x61 pc=0x1007dfca8]
goroutine 211890 [running]:
database/sql.(*Rows).closemuRUnlockIfHeldByScan(0x1400a08a000?)
/nix/store/f4a0g1p943l61wfvqnpdr73v9bsyfhf2-go-1.24.4/share/go/src/database/sql/sql.go:3412 +0x18
database/sql.(*Rows).Close(0x0)
/nix/store/f4a0g1p943l61wfvqnpdr73v9bsyfhf2-go-1.24.4/share/go/src/database/sql/sql.go:3439 +0x20
git.eeqj.de/sneak/routewatch/internal/database.(*Database).GetPrefixDistributionContext.func1()
/Users/user/dev/routewatch/internal/database/database.go:915 +0x24
git.eeqj.de/sneak/routewatch/internal/database.(*Database).GetPrefixDistributionContext(0x14000166820, {0x100e271b0, 0x140002004d0})
/Users/user/dev/routewatch/internal/database/database.go:935 +0x2fc
git.eeqj.de/sneak/routewatch/internal/database.(*Database).GetStatsContext(0x14000166820, {0x100e271b0, 0x140002004d0})
/Users/user/dev/routewatch/internal/database/database.go:813 +0x4ec
git.eeqj.de/sneak/routewatch/internal/server.(*Server).setupRoutes.func1.(*Server).handleStats.1.1()
/Users/user/dev/routewatch/internal/server/handlers.go:236 +0x6c
created by git.eeqj.de/sneak/routewatch/internal/server.(*Server).setupRoutes.func1.(*Server).handleStats.1 in goroutine 211873
/Users/user/dev/routewatch/internal/server/handlers.go:235 +0x1b8
Reference in New Issue View Git Blame Copy Permalink