2026-06-22T09:16:53.406Z|00001|vlog|INFO|opened log file /var/log/ovn/ovn-northd.log 2026-06-22T09:16:53.407Z|00002|ovn_northd|INFO|OVN internal version is : [24.03.6-20.33.0-76.8] 2026-06-22T09:16:53.407Z|00003|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T09:16:53.407Z|00004|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connected 2026-06-22T09:16:53.407Z|00005|ovn_northd|INFO|OVN NB IDL reconnected, force recompute. 2026-06-22T09:16:53.407Z|00006|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T09:16:53.407Z|00007|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connected 2026-06-22T09:16:53.407Z|00008|ovn_northd|INFO|OVN SB IDL reconnected, force recompute. 2026-06-22T09:16:53.408Z|00009|ovn_northd|INFO|ovn-northd lock acquired. This ovn-northd instance is now active. 2026-06-22T09:16:53.411Z|00010|memory_trim|INFO|Detected inactivity (last active 0 ms ago): trimming memory 2026-06-22T09:17:23.435Z|00011|memory|INFO|7460 kB peak resident set size after 30.0 seconds 2026-06-22T09:17:23.435Z|00012|memory|INFO|idl-cells-OVN_Northbound:12 idl-cells-OVN_Southbound:185 2026-06-22T09:17:23.435Z|00013|memory_trim|INFO|Detected inactivity (last active 30023 ms ago): trimming memory 2026-06-22T09:21:06.335Z|00014|ovn_parallel_hmap|INFO|Setting thread count to 0 2026-06-22T09:21:06.730Z|00001|vlog|INFO|opened log file /var/log/ovn/ovn-northd.log 2026-06-22T09:21:06.731Z|00002|ovn_northd|INFO|OVN internal version is : [24.03.6-20.33.0-76.8] 2026-06-22T09:21:06.731Z|00003|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T09:21:06.731Z|00004|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connection attempt failed (No such file or directory) 2026-06-22T09:21:06.731Z|00005|ovn_northd|INFO|OVN NB IDL reconnected, force recompute. 2026-06-22T09:21:06.731Z|00006|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T09:21:06.731Z|00007|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connection attempt failed (No such file or directory) 2026-06-22T09:21:06.731Z|00008|ovn_northd|INFO|OVN SB IDL reconnected, force recompute. 2026-06-22T09:21:07.732Z|00009|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connecting... 2026-06-22T09:21:07.733Z|00010|reconnect|INFO|unix:/var/run/ovn/ovnnb_db.sock: connected 2026-06-22T09:21:07.733Z|00011|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connecting... 2026-06-22T09:21:07.733Z|00012|reconnect|INFO|unix:/var/run/ovn/ovnsb_db.sock: connected 2026-06-22T09:21:07.733Z|00013|ovn_northd|INFO|ovn-northd lock acquired. This ovn-northd instance is now active. 2026-06-22T09:21:16.992Z|00014|memory|INFO|7332 kB peak resident set size after 10.3 seconds 2026-06-22T09:21:16.993Z|00015|memory|INFO|idl-cells-OVN_Northbound:26 idl-cells-OVN_Southbound:218 2026-06-22T09:22:11.649Z|00016|memory_trim|INFO|Detected inactivity (last active 30030 ms ago): trimming memory 2026-06-22T09:23:05.874Z|00017|memory_trim|INFO|Detected inactivity (last active 30022 ms ago): trimming memory 2026-06-22T09:23:46.064Z|00018|memory_trim|INFO|Detected inactivity (last active 30020 ms ago): trimming memory 2026-06-22T09:24:06.165Z|00019|memory|INFO|peak resident set size grew 58% in last 169.2 seconds, from 7332 kB to 11556 kB 2026-06-22T09:24:06.165Z|00020|memory|INFO|idl-cells-OVN_Northbound:2288 idl-cells-OVN_Southbound:13557 idl-outstanding-txns-OVN_Northbound:1 idl-outstanding-txns-OVN_Southbound:1 2026-06-22T09:26:33.940Z|00021|memory_trim|INFO|Detected inactivity (last active 30035 ms ago): trimming memory 2026-06-22T09:27:42.058Z|00022|ovn_northd|INFO|OVN_Northbound IDL run: 2 iterations in 6652 ms 2026-06-22T09:27:47.298Z|00001|timeval(stopwatch0)|WARN|Unreasonably long 6360ms poll interval (0ms user, 3423ms system) 2026-06-22T09:27:52.052Z|00002|timeval(stopwatch0)|WARN|faults: 16 minor, 163 major 2026-06-22T09:27:52.052Z|00003|timeval(stopwatch0)|WARN|disk: 40328 reads, 0 writes 2026-06-22T09:27:52.052Z|00004|timeval(stopwatch0)|WARN|context switches: 168 voluntary, 3805 involuntary 2026-06-22T09:27:52.052Z|00005|coverage(stopwatch0)|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=6caead25: 2026-06-22T09:27:52.052Z|00006|coverage(stopwatch0)|INFO|util_xalloc 3374.0/sec 5061.400/sec 2364.1158/sec total: 8510817 2026-06-22T09:27:52.052Z|00007|coverage(stopwatch0)|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T09:27:52.052Z|00008|coverage(stopwatch0)|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T09:27:52.052Z|00009|coverage(stopwatch0)|INFO|seq_change 5.0/sec 5.700/sec 2.3989/sec total: 8636 2026-06-22T09:27:52.052Z|00010|coverage(stopwatch0)|INFO|poll_create_node 9.2/sec 12.533/sec 5.3528/sec total: 19270 2026-06-22T09:27:52.052Z|00011|coverage(stopwatch0)|INFO|txn_success 1.0/sec 0.250/sec 0.1428/sec total: 514 2026-06-22T09:27:52.052Z|00012|coverage(stopwatch0)|INFO|txn_incomplete 1.4/sec 0.333/sec 0.1789/sec total: 644 2026-06-22T09:27:52.052Z|00013|coverage(stopwatch0)|INFO|txn_unchanged 0.6/sec 0.800/sec 0.3747/sec total: 1349 2026-06-22T09:27:52.052Z|00014|coverage(stopwatch0)|INFO|hmap_reserve 6.6/sec 10.317/sec 5.0744/sec total: 18268 2026-06-22T09:27:52.052Z|00015|coverage(stopwatch0)|INFO|hmap_expand 63.4/sec 100.450/sec 48.9242/sec total: 176127 2026-06-22T09:27:52.052Z|00016|coverage(stopwatch0)|INFO|hmap_pathological 1.4/sec 1.400/sec 0.5581/sec total: 2009 2026-06-22T09:27:52.052Z|00017|coverage(stopwatch0)|INFO|northd_run 0.8/sec 0.183/sec 0.1219/sec total: 439 2026-06-22T09:27:52.052Z|00018|coverage(stopwatch0)|INFO|103 events never hit 2026-06-22T09:27:52.054Z|00023|memory_trim|INFO|Detected inactivity (last active 51012 ms ago): trimming memory 2026-06-22T09:27:52.054Z|00024|timeval|WARN|Unreasonably long 20361ms poll interval (35ms user, 11956ms system) 2026-06-22T09:27:52.054Z|00025|timeval|WARN|faults: 60 minor, 575 major 2026-06-22T09:27:52.054Z|00026|timeval|WARN|disk: 138136 reads, 8 writes 2026-06-22T09:27:52.054Z|00027|timeval|WARN|context switches: 588 voluntary, 13459 involuntary 2026-06-22T09:27:52.054Z|00028|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=99e979de: 2026-06-22T09:27:52.054Z|00029|coverage|INFO|util_xalloc 14815.0/sec 7008.100/sec 2405.2686/sec total: 8659011 2026-06-22T09:27:52.054Z|00030|coverage|INFO|long_poll_interval 0.0/sec 0.000/sec 0.0000/sec total: 1 2026-06-22T09:27:52.055Z|00031|coverage|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T09:27:52.055Z|00032|coverage|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T09:27:52.055Z|00033|coverage|INFO|seq_change 0.8/sec 5.767/sec 2.4011/sec total: 8645 2026-06-22T09:27:52.055Z|00034|coverage|INFO|poll_create_node 3.2/sec 12.867/sec 5.3617/sec total: 19304 2026-06-22T09:27:52.055Z|00035|coverage|INFO|txn_success 0.0/sec 0.250/sec 0.1428/sec total: 514 2026-06-22T09:27:52.055Z|00036|coverage|INFO|txn_incomplete 0.0/sec 0.333/sec 0.1789/sec total: 644 2026-06-22T09:27:52.055Z|00037|coverage|INFO|txn_unchanged 1.6/sec 1.000/sec 0.3792/sec total: 1365 2026-06-22T09:27:52.055Z|00038|coverage|INFO|hmap_reserve 36.4/sec 15.117/sec 5.1756/sec total: 18632 2026-06-22T09:27:52.055Z|00039|coverage|INFO|hmap_expand 306.0/sec 140.800/sec 49.7739/sec total: 179186 2026-06-22T09:27:52.055Z|00040|coverage|INFO|hmap_pathological 3.4/sec 1.783/sec 0.5672/sec total: 2042 2026-06-22T09:27:52.055Z|00041|coverage|INFO|northd_run 0.8/sec 0.300/sec 0.1239/sec total: 446 2026-06-22T09:27:52.055Z|00042|coverage|INFO|102 events never hit 2026-06-22T09:27:52.480Z|00043|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:52.500Z|00044|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.470Z|00045|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.479Z|00046|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.576Z|00047|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.614Z|00048|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.621Z|00049|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.648Z|00050|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.717Z|00051|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:27:54.778Z|00052|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (58% CPU usage) 2026-06-22T09:28:34.390Z|00053|memory_trim|INFO|Detected inactivity (last active 30027 ms ago): trimming memory 2026-06-22T09:29:24.092Z|00054|inc_proc_eng|INFO|node: northd, recompute (failed handler for input NB_logical_switch) took 16294ms 2026-06-22T09:29:24.099Z|00055|timeval|WARN|Unreasonably long 16327ms poll interval (2ms user, 13664ms system) 2026-06-22T09:29:24.099Z|00056|timeval|WARN|faults: 127 minor, 1737 major 2026-06-22T09:29:24.099Z|00057|timeval|WARN|disk: 444048 reads, 8 writes 2026-06-22T09:29:24.099Z|00058|timeval|WARN|context switches: 1773 voluntary, 12960 involuntary 2026-06-22T09:29:24.099Z|00059|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour, hash=63e789fb: 2026-06-22T09:29:24.099Z|00060|coverage|INFO|util_xalloc 3656.0/sec 5245.367/sec 2579.6289/sec total: 9336790 2026-06-22T09:29:24.099Z|00061|coverage|INFO|long_poll_interval 0.0/sec 0.000/sec 0.0006/sec total: 2 2026-06-22T09:29:24.099Z|00062|coverage|INFO|stream_open 0.0/sec 0.000/sec 0.0011/sec total: 4 2026-06-22T09:29:24.099Z|00063|coverage|INFO|pstream_open 0.0/sec 0.000/sec 0.0003/sec total: 1 2026-06-22T09:29:24.099Z|00064|coverage|INFO|seq_change 6.4/sec 4.517/sec 2.5661/sec total: 9244 2026-06-22T09:29:24.099Z|00065|coverage|INFO|poll_create_node 13.2/sec 10.200/sec 5.7239/sec total: 20630 2026-06-22T09:29:24.099Z|00066|coverage|INFO|txn_success 0.4/sec 0.233/sec 0.1489/sec total: 538 2026-06-22T09:29:24.099Z|00067|coverage|INFO|txn_incomplete 0.4/sec 0.300/sec 0.1864/sec total: 674 2026-06-22T09:29:24.099Z|00068|coverage|INFO|txn_unchanged 0.4/sec 0.883/sec 0.4039/sec total: 1463 2026-06-22T09:29:24.099Z|00069|coverage|INFO|hmap_reserve 8.2/sec 11.583/sec 5.5589/sec total: 20133 2026-06-22T09:29:24.099Z|00070|coverage|INFO|hmap_expand 79.4/sec 112.167/sec 53.4475/sec total: 193483 2026-06-22T09:29:24.099Z|00071|coverage|INFO|hmap_pathological 0.8/sec 1.017/sec 0.6033/sec total: 2184 2026-06-22T09:29:24.099Z|00072|coverage|INFO|northd_run 0.2/sec 0.267/sec 0.1322/sec total: 479 2026-06-22T09:29:24.099Z|00073|coverage|INFO|102 events never hit 2026-06-22T09:29:24.099Z|00074|poll_loop|INFO|Dropped 4 log messages in last 89 seconds (most recently, 89 seconds ago) due to excessive rate 2026-06-22T09:29:24.099Z|00075|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:24.100Z|00076|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:24.106Z|00077|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.521Z|00078|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.620Z|00079|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.627Z|00080|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.690Z|00081|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.696Z|00082|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:26.938Z|00083|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:27.046Z|00084|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (72% CPU usage) 2026-06-22T09:29:39.943Z|00085|inc_proc_eng|INFO|node: northd, recompute (missing handler for input SB_datapath_binding) took 12881ms 2026-06-22T09:29:39.949Z|00086|timeval|WARN|Unreasonably long 12903ms poll interval (6ms user, 11436ms system) 2026-06-22T09:29:39.949Z|00087|timeval|WARN|faults: 153 minor, 1967 major 2026-06-22T09:29:39.949Z|00088|timeval|WARN|disk: 502200 reads, 16 writes 2026-06-22T09:29:39.949Z|00089|timeval|WARN|context switches: 2002 voluntary, 10307 involuntary 2026-06-22T09:29:39.949Z|00090|coverage|INFO|Skipping details of duplicate event coverage for hash=63e789fb 2026-06-22T09:29:43.248Z|00091|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (60% CPU usage) 2026-06-22T09:29:43.257Z|00092|poll_loop|INFO|wakeup due to [POLLIN] on fd 18 (<->/var/run/ovn/ovnsb_db.sock) at lib/stream-fd.c:157 (60% CPU usage) 2026-06-22T09:29:43.323Z|00093|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (60% CPU usage) 2026-06-22T09:29:47.086Z|00094|inc_proc_eng|INFO|node: mac_binding_aging, recompute (missing handler for input northd) took 3607ms 2026-06-22T09:29:47.086Z|00019|timeval(stopwatch0)|WARN|Unreasonably long 3597ms poll interval (0ms user, 1991ms system) 2026-06-22T09:29:47.086Z|00020|timeval(stopwatch0)|WARN|faults: 11 minor, 69 major 2026-06-22T09:29:47.086Z|00021|timeval(stopwatch0)|WARN|disk: 15600 reads, 0 writes 2026-06-22T09:29:47.086Z|00022|timeval(stopwatch0)|WARN|context switches: 70 voluntary, 2406 involuntary 2026-06-22T09:29:47.090Z|00095|timeval|WARN|Unreasonably long 3642ms poll interval (5ms user, 2378ms system) 2026-06-22T09:29:47.090Z|00096|timeval|WARN|faults: 56 minor, 155 major 2026-06-22T09:29:47.090Z|00097|timeval|WARN|disk: 30664 reads, 8 writes 2026-06-22T09:29:47.090Z|00098|timeval|WARN|context switches: 169 voluntary, 2748 involuntary 2026-06-22T09:29:49.485Z|00099|poll_loop|INFO|Dropped 8 log messages in last 7 seconds (most recently, 3 seconds ago) due to excessive rate 2026-06-22T09:29:49.486Z|00100|poll_loop|INFO|wakeup due to [POLLIN] on fd 17 (<->/var/run/ovn/ovnnb_db.sock) at lib/stream-fd.c:157 (63% CPU usage) 2026-06-22T09:30:54.919Z|00101|memory_trim|INFO|Detected inactivity (last active 31448 ms ago): trimming memory 2026-06-22T09:31:30.159Z|00102|memory_trim|INFO|Detected inactivity (last active 30034 ms ago): trimming memory 2026-06-22T09:32:26.564Z|00103|memory_trim|INFO|Detected inactivity (last active 31323 ms ago): trimming memory 2026-06-22T09:34:04.606Z|00104|memory_trim|INFO|Detected inactivity (last active 30030 ms ago): trimming memory 2026-06-22T09:35:27.259Z|00105|memory_trim|INFO|Detected inactivity (last active 30030 ms ago): trimming memory 2026-06-22T09:36:42.389Z|00106|memory_trim|INFO|Detected inactivity (last active 30005 ms ago): trimming memory