2026-06-22T13:40:54.697Z|00001|vlog|INFO|opened log file /var/log/ovn/ovn-northd.log 2026-06-22T13:40:54.698Z|00002|ovn_northd|INFO|OVN internal version is : [24.03.6-20.33.0-76.8] 2026-06-22T13:40:54.698Z|00003|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T13:40:54.698Z|00004|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connected 2026-06-22T13:40:54.698Z|00005|ovn_northd|INFO|OVN NB IDL reconnected, force recompute. 2026-06-22T13:40:54.698Z|00006|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T13:40:54.698Z|00007|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connected 2026-06-22T13:40:54.698Z|00008|ovn_northd|INFO|OVN SB IDL reconnected, force recompute. 2026-06-22T13:40:54.698Z|00009|ovn_northd|INFO|ovn-northd lock acquired. This ovn-northd instance is now active. 2026-06-22T13:40:54.701Z|00010|memory_trim|INFO|Detected inactivity (last active 0 ms ago): trimming memory 2026-06-22T13:41:24.737Z|00011|memory|INFO|7460 kB peak resident set size after 30.0 seconds 2026-06-22T13:41:24.737Z|00012|memory|INFO|idl-cells-OVN_Northbound:12 idl-cells-OVN_Southbound:185 2026-06-22T13:41:24.738Z|00013|memory_trim|INFO|Detected inactivity (last active 30036 ms ago): trimming memory 2026-06-22T13:45:09.307Z|00014|ovn_parallel_hmap|INFO|Setting thread count to 0 2026-06-22T13:45:09.696Z|00001|vlog|INFO|opened log file /var/log/ovn/ovn-northd.log 2026-06-22T13:45:09.697Z|00002|ovn_northd|INFO|OVN internal version is : [24.03.6-20.33.0-76.8] 2026-06-22T13:45:09.698Z|00003|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T13:45:09.698Z|00004|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connection attempt failed (No such file or directory) 2026-06-22T13:45:09.698Z|00005|ovn_northd|INFO|OVN NB IDL reconnected, force recompute. 2026-06-22T13:45:09.698Z|00006|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T13:45:09.698Z|00007|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connection attempt failed (No such file or directory) 2026-06-22T13:45:09.698Z|00008|ovn_northd|INFO|OVN SB IDL reconnected, force recompute. 2026-06-22T13:45:10.699Z|00009|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T13:45:10.699Z|00010|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connected 2026-06-22T13:45:10.699Z|00011|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T13:45:10.699Z|00012|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connected 2026-06-22T13:45:10.699Z|00013|ovn_northd|INFO|ovn-northd lock acquired. This ovn-northd instance is now active. 2026-06-22T13:45:20.494Z|00014|memory|INFO|7332 kB peak resident set size after 10.8 seconds 2026-06-22T13:45:20.494Z|00015|memory|INFO|idl-cells-OVN_Northbound:26 idl-cells-OVN_Southbound:218 2026-06-22T13:46:15.727Z|00016|memory_trim|INFO|Detected inactivity (last active 30031 ms ago): trimming memory 2026-06-22T13:47:11.560Z|00017|memory_trim|INFO|Detected inactivity (last active 30030 ms ago): trimming memory 2026-06-22T13:47:51.317Z|00018|memory_trim|INFO|Detected inactivity (last active 30027 ms ago): trimming memory 2026-06-22T13:48:25.566Z|00019|memory|INFO|peak resident set size grew 56% in last 185.1 seconds, from 7332 kB to 11428 kB 2026-06-22T13:48:25.566Z|00020|memory|INFO|idl-cells-OVN_Northbound:2458 idl-cells-OVN_Southbound:14175 2026-06-22T13:50:03.041Z|00021|inc_proc_eng|INFO|node: lflow, recompute (failed handler for input northd) took 1863ms 2026-06-22T13:50:03.042Z|00022|timeval|WARN|Unreasonably long 2220ms poll interval (44ms user, 1412ms system) 2026-06-22T13:50:03.042Z|00023|timeval|WARN|faults: 273 minor, 1743 major 2026-06-22T13:50:03.042Z|00024|timeval|WARN|disk: 403320 reads, 8 writes 2026-06-22T13:50:03.042Z|00025|timeval|WARN|context switches: 1736 voluntary, 463 involuntary 2026-06-22T13:50:03.042Z|00026|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=da0b649c: 2026-06-22T13:50:03.042Z|00027|coverage|INFO|util_xalloc 100674.4/sec 89579.750/sec 3818.9411/sec total: 13806970 2026-06-22T13:50:03.042Z|00028|coverage|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T13:50:03.042Z|00029|coverage|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T13:50:03.042Z|00030|coverage|INFO|seq_change 89.2/sec 73.717/sec 3.5825/sec total: 12903 2026-06-22T13:50:03.042Z|00031|coverage|INFO|poll_create_node 195.6/sec 164.633/sec 7.9483/sec total: 28638 2026-06-22T13:50:03.042Z|00032|coverage|INFO|txn_success 5.0/sec 4.450/sec 0.2011/sec total: 727 2026-06-22T13:50:03.042Z|00033|coverage|INFO|txn_incomplete 5.8/sec 5.367/sec 0.2542/sec total: 920 2026-06-22T13:50:03.042Z|00034|coverage|INFO|txn_unchanged 11.4/sec 11.833/sec 0.5283/sec total: 1909 2026-06-22T13:50:03.042Z|00035|coverage|INFO|hmap_reserve 279.4/sec 225.200/sec 8.9219/sec total: 32286 2026-06-22T13:50:03.042Z|00036|coverage|INFO|hmap_expand 1996.2/sec 1743.267/sec 77.9408/sec total: 281773 2026-06-22T13:50:03.042Z|00037|coverage|INFO|hmap_pathological 42.4/sec 48.317/sec 1.7664/sec total: 6384 2026-06-22T13:50:03.042Z|00038|coverage|INFO|northd_run 3.4/sec 3.333/sec 0.1747/sec total: 631 2026-06-22T13:50:03.042Z|00039|coverage|INFO|103 events never hit 2026-06-22T13:50:35.121Z|00040|memory_trim|INFO|Detected inactivity (last active 31903 ms ago): trimming memory 2026-06-22T13:50:35.870Z|00041|timeval|WARN|Unreasonably long 2457ms poll interval (26ms user, 2178ms system) 2026-06-22T13:50:36.134Z|00042|timeval|WARN|faults: 63 minor, 554 major 2026-06-22T13:50:36.158Z|00043|timeval|WARN|disk: 141600 reads, 8 writes 2026-06-22T13:50:36.160Z|00044|timeval|WARN|context switches: 566 voluntary, 1688 involuntary 2026-06-22T13:50:36.655Z|00045|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=bd0e16dc: 2026-06-22T13:50:36.920Z|00046|coverage|INFO|util_xalloc 1962.6/sec 41997.900/sec 3835.2961/sec total: 13835385 2026-06-22T13:50:37.059Z|00047|coverage|INFO|long_poll_interval 0.0/sec 0.000/sec 0.0000/sec total: 1 2026-06-22T13:50:37.399Z|00048|coverage|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T13:50:37.639Z|00049|coverage|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T13:50:38.096Z|00050|coverage|INFO|seq_change 1.0/sec 35.217/sec 3.5908/sec total: 12932 2026-06-22T13:50:38.393Z|00051|coverage|INFO|poll_create_node 2.4/sec 79.417/sec 7.9683/sec total: 28704 2026-06-22T13:50:39.096Z|00052|coverage|INFO|txn_success 0.6/sec 2.467/sec 0.2019/sec total: 729 2026-06-22T13:50:40.394Z|00053|coverage|INFO|txn_incomplete 1.0/sec 2.950/sec 0.2556/sec total: 924 2026-06-22T13:50:42.309Z|00054|coverage|INFO|txn_unchanged 0.4/sec 6.083/sec 0.5303/sec total: 1913 2026-06-22T13:50:44.125Z|00055|coverage|INFO|hmap_reserve 6.4/sec 110.517/sec 8.9683/sec total: 32369 2026-06-22T13:50:44.126Z|00056|coverage|INFO|hmap_expand 40.2/sec 807.483/sec 78.2703/sec total: 282320 2026-06-22T13:50:44.126Z|00057|coverage|INFO|hmap_pathological 1.0/sec 20.833/sec 1.7733/sec total: 6396 2026-06-22T13:50:44.126Z|00058|coverage|INFO|northd_run 0.4/sec 1.500/sec 0.1753/sec total: 632 2026-06-22T13:50:44.126Z|00059|coverage|INFO|102 events never hit 2026-06-22T13:50:44.464Z|00060|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:44.476Z|00061|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:44.477Z|00062|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:44.486Z|00063|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.122Z|00064|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.129Z|00065|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.391Z|00066|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.391Z|00067|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.391Z|00068|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:50:46.395Z|00069|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (90% CPU usage) 2026-06-22T13:51:17.605Z|00070|memory_trim|INFO|Detected inactivity (last active 30318 ms ago): trimming memory 2026-06-22T13:53:46.919Z|00001|timeval(stopwatch0)|WARN|Unreasonably long 8233ms poll interval (0ms user, 3485ms system) 2026-06-22T13:53:46.920Z|00002|timeval(stopwatch0)|WARN|faults: 20 minor, 117 major 2026-06-22T13:53:46.920Z|00003|timeval(stopwatch0)|WARN|disk: 28192 reads, 0 writes 2026-06-22T13:53:46.920Z|00004|timeval(stopwatch0)|WARN|context switches: 122 voluntary, 4424 involuntary 2026-06-22T13:53:46.920Z|00005|coverage(stopwatch0)|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=2fead117: 2026-06-22T13:53:46.920Z|00006|coverage(stopwatch0)|INFO|util_xalloc 3121.8/sec 8145.167/sec 4134.3419/sec total: 14883631 2026-06-22T13:53:46.920Z|00007|coverage(stopwatch0)|INFO|long_poll_interval 0.0/sec 0.000/sec 0.0006/sec total: 2 2026-06-22T13:53:46.920Z|00008|coverage(stopwatch0)|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T13:53:46.920Z|00009|coverage(stopwatch0)|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T13:53:46.920Z|00010|coverage(stopwatch0)|INFO|seq_change 2.8/sec 6.967/sec 3.8517/sec total: 13866 2026-06-22T13:53:46.920Z|00011|coverage(stopwatch0)|INFO|poll_create_node 6.2/sec 15.567/sec 8.5606/sec total: 30818 2026-06-22T13:53:46.920Z|00012|coverage(stopwatch0)|INFO|txn_success 1.2/sec 0.433/sec 0.2194/sec total: 790 2026-06-22T13:53:46.920Z|00013|coverage(stopwatch0)|INFO|txn_incomplete 1.2/sec 0.450/sec 0.2750/sec total: 990 2026-06-22T13:53:46.920Z|00014|coverage(stopwatch0)|INFO|txn_unchanged 0.8/sec 1.217/sec 0.5814/sec total: 2093 2026-06-22T13:53:46.920Z|00015|coverage(stopwatch0)|INFO|hmap_reserve 10.2/sec 23.050/sec 9.7764/sec total: 35195 2026-06-22T13:53:46.920Z|00016|coverage(stopwatch0)|INFO|hmap_expand 64.0/sec 164.883/sec 84.2022/sec total: 303128 2026-06-22T13:53:46.920Z|00017|coverage(stopwatch0)|INFO|hmap_pathological 2.0/sec 4.717/sec 1.9258/sec total: 6933 2026-06-22T13:53:46.920Z|00018|coverage(stopwatch0)|INFO|northd_run 1.2/sec 0.350/sec 0.1861/sec total: 670 2026-06-22T13:53:46.920Z|00019|coverage(stopwatch0)|INFO|102 events never hit 2026-06-22T13:53:46.920Z|00071|ovn_northd|INFO|OVN_Northbound IDL run: 2 iterations in 8477 ms 2026-06-22T13:53:46.921Z|00072|memory_trim|INFO|Detected inactivity (last active 40782 ms ago): trimming memory 2026-06-22T13:53:46.922Z|00073|timeval|WARN|Unreasonably long 9884ms poll interval (0ms user, 5260ms system) 2026-06-22T13:53:46.922Z|00074|timeval|WARN|faults: 23 minor, 232 major 2026-06-22T13:53:46.922Z|00075|timeval|WARN|disk: 56136 reads, 0 writes 2026-06-22T13:53:46.922Z|00076|timeval|WARN|context switches: 240 voluntary, 6330 involuntary 2026-06-22T13:53:46.922Z|00077|coverage|INFO|Skipping details of duplicate event coverage for hash=2fead117