TurtleBot tf topic: “A message was lost"

[BashByr]

Please provide the following information:

• OS: Ubuntu 22.04.1
• ROS Distro: Humble
• Built from source or installed: Installed

Expected behaviour
To read in all /tf messages when running the command ros2 topic echo tbot1/tf

Actual behaviour
The terminal fills up mostly with “A message was lost” warnings, as shown below:

To Reproduce
Simply running ros2 topic echo tbot1/tf. The robot was docked. As seen in the Create3 logs below, the Create3 CPU is frequently at or near 100% usage.

Create3 logs

Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137237] WARNING: CPU: 0 PID: 2189 at /home/ubuntu/workspace/build/tmp/work-shared/sundial/kernel-source/kernel/kthread.c:761 kthread_insert_work+0x24/0x78 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137241] Modules linked in: snd_soc_max98357a xt_limit nf_conntrack_ipv4 nf_defrag_ipv4 xt_tcpudp xt_conntrack nf_conntrack iptable_filter iptable_mangle ip_tables x_tables usb_storage snd_soc_ralink_i2s sd_mod scsi_mod rt Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137362] CPU: 0 PID: 2189 Comm: MSIprotoUpdate Tainted: P 4.14.115-yocto-standard-custom #1 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137368] Stack : 80450000 00000009 00000000 00000000 804cf824 83807d64 82232edc 8053b467 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137399] 804cae4c 0000088d 80593660 000002f9 00000000 00000001 83807d18 c52a5173 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137427] 00000000 00000000 80590000 00000003 00000000 000000fc 00000000 00000000 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137454] 00000000 000000fb 805b0000 6463206d 80000000 00000000 80039d7c 804ce428 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137482] 00000009 000002f9 00000000 80550000 00000001 83a98ae0 00000000 80590000 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137510] ... Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137518] Call Trace: Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137551] [<8000a28c>] show_stack+0x74/0x104 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137566] [<80021394>] __warn+0x110/0x11c Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137599] [<80021034>] warn_slowpath_null+0x1c/0x28 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137613] [<80039d7c>] kthread_insert_work+0x24/0x78 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137625] [<80039e08>] kthread_queue_work+0x38/0x60 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137659] [<802156e0>] serial8250_rx_chars+0x110/0x1ec Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137679] [<80216d04>] serial8250_handle_irq+0x90/0x11c Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137697] [<80217188>] serial8250_default_handle_irq+0x30/0x50 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137711] [<802142c8>] serial8250_interrupt+0x44/0xd8 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137726] [<8004eb0c>] __handle_irq_event_percpu+0x98/0x160 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137737] [<8004ebf4>] handle_irq_event_percpu+0x20/0x64 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137748] [<8004ec74>] handle_irq_event+0x3c/0x68 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137769] [<800524a0>] handle_level_irq+0xf4/0x12c Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137782] [<8004e270>] generic_handle_irq+0x28/0x38 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137793] [<8004e270>] generic_handle_irq+0x28/0x38 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137815] [<8041b920>] do_IRQ+0x18/0x24 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137827] [<80005810>] except_vec_vi_end+0xb8/0xc4 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137855] [<80416d3c>] __copy_user+0x38/0x2bc Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137886] [<801d3bd4>] xz_dec_lzma2_run+0x1cc/0x7fc Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137900] [<801d2590>] xz_dec_run+0x368/0x8ec Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137922] [<80130fb0>] squashfs_xz_uncompress+0x110/0x1ec Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137933] [<8013077c>] squashfs_decompress+0x48/0x80 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137944] [<8012c304>] squashfs_read_data+0x224/0x6d0 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137955] [<8012c9c0>] squashfs_cache_get+0x210/0x2c0 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137967] [<8012fffc>] squashfs_readpage_block+0x16c/0x580 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137980] [<8012e198>] squashfs_readpage+0x60c/0x6d4 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.137992] [<80092a64>] __do_page_cache_readahead+0x20c/0x25c Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138013] [<80087840>] filemap_fault+0x2bc/0x594 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138033] [<800a8b78>] __do_fault+0xfc/0x174 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138051] [<800acadc>] handle_mm_fault+0x598/0xabc Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138074] [<800112e4>] __do_page_fault+0x2e4/0x4d0 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138095] [<80016e8c>] tlb_do_page_fault_0+0x10c/0x114 Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 kern.warn kernel: [ 155.138107] ---[ end trace 0de90439b8584d5a ]--- Apr 27 12:36:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682598977.696151120] [tbot1._internal.mobility]: waiting for config packet...../../modules/mobility-node/src/mobility-node.cpp:295 Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'MSIprotoUpdate' task to resume Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSIprotoUpdate' task resuming Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSIprotoUpdate' task resumed Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'MSIrobotRx' task to resume Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSIrobotRx' task resuming Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSIrobotRx' task resumed Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'MSImobPinger' task to resume Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSImobPinger' task resuming Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSImobPinger' task resumed Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'MSItimeSync' task to resume Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSItimeSync' task resuming Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'MSItimeSync' task resumed Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] proto event : PP_NOTIFY_SYNCED Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: proto event : PP_NOTIFY_SYNCED Apr 27 12:36:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosMousePub_dur_us Apr 27 12:36:21 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_hzd_seq_num_latency_ms Apr 27 12:36:21 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 216.229.4.69: delay 0.267623 is too high, ignoring Apr 27 12:36:22 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682598982: New connection from 127.0.0.1 on port 1883. Apr 27 12:36:22 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682598982: New client connected from 127.0.0.1 as mosqpub/2223-iRobot-874 (c1, k60). Apr 27 12:36:22 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682598982: Client mosqpub/2223-iRobot-874 disconnected. Apr 27 12:36:28 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosKinemEngineTimer_dur_us Apr 27 12:36:28 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosKinemEngineTimer_int_ms Apr 27 12:36:28 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_kinem_engine_deadreck_int_ms Apr 27 12:36:28 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682598988.608459917] [tbot1._internal.kinematics_engine]: Node created Apr 27 12:36:34 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosHazardsTimer_dur_us Apr 27 12:36:34 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosHazardsTimer_int_ms Apr 27 12:36:34 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosActiveIrAccessoryPub_dur_us Apr 27 12:36:34 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_rosActiveHazardsPub_dur_us Apr 27 12:36:34 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682598994.136865111] [tbot1._internal.composite_hazard]: Node created Apr 27 12:36:40 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599000.219459666] [tbot1._internal.stasis]: Node created Apr 27 12:36:42 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 32s Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.235077455] [tbot1.motion_control]: Setting safety override to "none" Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.572951490] [tbot1.motion_control]: Enabling REFLEX_WHEEL_DROP Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.587940492] [tbot1.motion_control]: Enabling REFLEX_CLIFF Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.590594052] [tbot1.motion_control]: Enabling REFLEX_GYRO_CAL Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.601406103] [tbot1.motion_control]: Enabling REFLEX_STUCK Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.602996635] [tbot1.motion_control]: Enabling REFLEX_PANIC Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.606554037] [tbot1.motion_control]: Enabling REFLEX_BUMP Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.610512941] [tbot1.motion_control]: Disabling REFLEX_DOCK_AVOID Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.612349080] [tbot1.motion_control]: Disabling REFLEX_VIRTUAL_WALL Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599006.631815590] [tbot1.motion_control]: Enabling REFLEX_PROXIMITY_SLOWDOWN Apr 27 12:36:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WARN] [1682599006.635947723] [tbot1.motion_control]: Enabling reflexes Apr 27 12:36:52 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599012.637771247] [tbot1.motion_control]: Node created Apr 27 12:36:54 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599014: New connection from 127.0.0.1 on port 1883. Apr 27 12:36:54 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599014: New client connected from 127.0.0.1 as mosqpub/2307-iRobot-874 (c1, k60). Apr 27 12:36:54 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599014: Client mosqpub/2307-iRobot-874 disconnected. Apr 27 12:36:58 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599018.505354141] [tbot1.mobility_monitor]: Node created Apr 27 12:37:06 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599026.444848774] [tbot1.ui_mgr]: Node created Apr 27 12:37:12 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599032.939805207] [tbot1.robot_state]: Node created Apr 27 12:37:19 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599039.751769713] [tbot1.static_transform]: Node created Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 10 id: 25 Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [WheelDrop] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [Cliff] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [GyroCal] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [Stuck] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [Panic] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [Bump] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: enable [Proximity Slowdown] Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] Refl: Arbiter on Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] ThermalMonitor - Could not read thermal configuration from /etc/thermal-engine.conf... setting values to default Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_os_temp_c Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for os_cpu_active Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: VSTAT: No config for vstat_nav_os_meminfo_kb Apr 27 12:37:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599046.992967434] [tbot1.system_health]: Node created Apr 27 12:37:31 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 32s Apr 27 12:37:37 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599057.941931916] [create-platform]: Configuring mobility node Apr 27 12:37:38 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599058.425323907] [create-platform]: Activating mobility node Apr 27 12:37:38 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599058.569110468] [tbot1._internal.mobility]: Lifecycle callback: on_activate Apr 27 12:37:40 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599060.658438933] [create-platform]: Started mobility node Apr 27 12:37:40 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599060.659920688] [create-platform]: Configuring kinematics_engine node Apr 27 12:37:40 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599060.660355075] [tbot1._internal.kinematics_engine]: Lifecycle callback: on_configure Apr 27 12:37:40 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599060.901734830] [tbot1._internal.kinematics_engine]: on_configure(): requesting mouse cal parameters Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599061.098952057] [tbot1._internal.kinematics_engine]: on_configure(): received mouse cal parameters Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] OSMonitor::OSMonitor: [ CREATED OS MONITOR ] Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 46 id: 25 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'internal_nodes' task to resume Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'internal_nodes' task resuming Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'internal_nodes' task resumed Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'nodes_0' task to resume Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'nodes_0' task resuming Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'nodes_0' task resumed Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] Waiting for 'nodes_1' task to resume Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'nodes_1' task resuming Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [DBG] [TSSM] 'nodes_1' task resumed Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 95 id: 25 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 206 id: 18 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 74 id: 25 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 106 id: 25 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 118 id: 30 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 455 id: 65 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 78 id: 25 Apr 27 12:37:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 122 id: 25 Apr 27 12:37:42 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599062: New connection from 127.0.0.1 on port 1883. Apr 27 12:37:42 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599062: New client connected from 127.0.0.1 as mosqpub/2438-iRobot-874 (c1, k60). Apr 27 12:37:42 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599062: Client mosqpub/2438-iRobot-874 disconnected. Apr 27 12:37:43 iRobot-8748D7279D6349E98FCA76C83EF27D99 daemon.notice network[1468]: [INFO] (src/provisioning_sm.c:542) provisioning_state_machine_run: rx event PROVISIONING_COMPLETE in state PS_NONE Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: ifdown: interface wlan1 not configured Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 daemon.notice network[1468]: [INFO] (src/wifi_control.c:399) SoftAP is down Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 daemon.notice network[1468]: [INFO] (src/wifi_control.c:245) iface control: sudo network_device_interfaces_control.sh --interface=softap --action=del Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: We trust you have received the usual lecture from the local System Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: Administrator. It usually boils down to these three things: Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: #1) Respect the privacy of others. Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: #2) Think before you type. Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: #3) With great power comes great responsibility. Apr 27 12:37:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice network_manager: sudo: a terminal is required to read the password; either use the -S option to read from standard input or configure an askpass helper Apr 27 12:37:48 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: [INFO] [1682599068.544326767] [create-platform]: Activating kinematics_engine node Apr 27 12:37:48 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599068.549599106] [tbot1._internal.kinematics_engine]: Lifecycle callback: on_activate Apr 27 12:37:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599069.551809740] [create-platform]: Started kinematics_engine node Apr 27 12:37:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599069.558277136] [create-platform]: Configuring composite_hazard node Apr 27 12:37:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599069.558833166] [tbot1._internal.composite_hazard]: Lifecycle callback: on_configure Apr 27 12:37:55 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599075.966710216] [create-platform]: Activating composite_hazard node Apr 27 12:37:55 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599075.967987169] [tbot1._internal.composite_hazard]: Lifecycle callback: on_activate Apr 27 12:37:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599076.142666317] [tbot1.motion_control]: Kidnap status changed: temporarily enabling reflexes Apr 27 12:37:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WARN] [1682599076.265863882] [tbot1.motion_control]: Enabling reflexes Apr 27 12:37:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599076.974283392] [create-platform]: Started composite_hazard node Apr 27 12:37:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599076.974478711] [create-platform]: Configuring stasis node Apr 27 12:37:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599076.974811189] [tbot1._internal.stasis]: Lifecycle callback: on_configure Apr 27 12:37:57 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599077.082010483] [tbot1._internal.stasis]: on_configure(): requesting mouse cal parameters Apr 27 12:37:57 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599077.084805968] [tbot1._internal.stasis]: on_configure(): received mouse cal parameters Apr 27 12:38:03 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599083.160006027] [create-platform]: Activating stasis node Apr 27 12:38:03 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599083.160356932] [tbot1._internal.stasis]: Lifecycle callback: on_activate Apr 27 12:38:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599084.161649922] [create-platform]: Started stasis node Apr 27 12:38:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599084.167209738] [create-platform]: Configuring mobility_monitor node Apr 27 12:38:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599084.167596142] [tbot1.mobility_monitor]: Lifecycle callback: on_configure Apr 27 12:38:09 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599089.629576465] [create-platform]: Activating mobility_monitor node Apr 27 12:38:09 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599089.629923645] [tbot1.mobility_monitor]: Lifecycle callback: on_activate Apr 27 12:38:09 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599089.637317253] [tbot1.mobility_monitor]: New kidnap status: kidnap cleared Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.240746429] [tbot1._internal.mobility]: Received enable wheels request Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.245213347] [tbot1.mobility_monitor]: Requested to enable wheels! Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.485154523] [tbot1.mobility_monitor]: Updating ready to drive: true Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.485952428] [tbot1.mobility_monitor]: Kidnap cleared! Wheels are now enabled! Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.630724540] [create-platform]: Started mobility_monitor node Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.630913755] [create-platform]: Configuring robot_state node Apr 27 12:38:10 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599090.632641353] [tbot1.robot_state]: Lifecycle callback: on_configure Apr 27 12:38:19 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 32s Apr 27 12:38:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599107.528162154] [tbot1.system_health]: CPU usage: max 100 [%] mean 77 [%] RAM usage: 38/59 [MB] Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: 65 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 87 id: 81 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 128 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 23 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 29 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 60 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 85 id: 90 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 73 id: 81 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 59 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 12 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 21 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 74 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 18 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 82 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 176 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 281 id: 25 Apr 27 12:38:33 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 57 id: 18 Apr 27 12:38:37 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599117: New connection from 127.0.0.1 on port 1883. Apr 27 12:38:37 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599117: New client connected from 127.0.0.1 as mosqpub/2568-iRobot-874 (c1, k60). Apr 27 12:38:37 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599117: Client mosqpub/2568-iRobot-874 disconnected. Apr 27 12:38:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [WAR] Packet handler running too long exec_time: 144[INFO] [1682599124.154924914] [create-platform]: Activating robot_state node Apr 27 12:38:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599124.156588249] [tbot1.robot_state]: Lifecycle callback: on_activate Apr 27 12:38:45 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599125.171284562] [create-platform]: Started robot_state node Apr 27 12:38:45 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599125.181861352] [create-platform]: Configuring static_transform node Apr 27 12:38:55 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599135.698162924] [create-platform]: Activating static_transform node Apr 27 12:38:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599136.710594436] [create-platform]: Started static_transform node Apr 27 12:38:57 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599137.039960607] [create-platform]: Ready to go! Apr 27 12:39:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599145: New connection from 127.0.0.1 on port 1883. Apr 27 12:39:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599145: New client connected from 127.0.0.1 as mosqpub/2637-iRobot-874 (c1, k60). Apr 27 12:39:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599145: Client mosqpub/2637-iRobot-874 disconnected. Apr 27 12:39:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 66s Apr 27 12:39:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599167.083528506] [tbot1.system_health]: CPU usage: max 100 [%] mean 92 [%] RAM usage: 38/59 [MB] Apr 27 12:40:11 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599211: New connection from 127.0.0.1 on port 1883. Apr 27 12:40:11 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599211: New client connected from 127.0.0.1 as mosqpub/2808-iRobot-874 (c1, k60). Apr 27 12:40:11 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599211: Client mosqpub/2808-iRobot-874 disconnected. Apr 27 12:40:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599226.997688436] [tbot1.system_health]: CPU usage: max 96 [%] mean 87 [%] RAM usage: 38/59 [MB] Apr 27 12:40:30 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 67s Apr 27 12:41:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.002487 is too high, ignoring Apr 27 12:41:18 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599278: New connection from 127.0.0.1 on port 1883. Apr 27 12:41:18 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599278: New client connected from 127.0.0.1 as mosqpub/2972-iRobot-874 (c1, k60). Apr 27 12:41:18 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682599278: Client mosqpub/2972-iRobot-874 disconnected. Apr 27 12:41:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599286.997385568] [tbot1.system_health]: CPU usage: max 95 [%] mean 87 [%] RAM usage: 38/59 [MB] Apr 27 12:41:53 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 67s Apr 27 12:42:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599346.999872580] [tbot1.system_health]: CPU usage: max 95 [%] mean 89 [%] RAM usage: 38/59 [MB] Apr 27 12:43:15 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.005486 is too high, ignoring Apr 27 12:43:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 131s Apr 27 12:43:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599406.998686759] [tbot1.system_health]: CPU usage: max 96 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 12:44:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599467.006787743] [tbot1.system_health]: CPU usage: max 94 [%] mean 87 [%] RAM usage: 39/59 [MB] Apr 27 12:45:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599527.005948488] [tbot1.system_health]: CPU usage: max 95 [%] mean 87 [%] RAM usage: 39/59 [MB] Apr 27 12:45:44 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 133s Apr 27 12:46:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599586.994243409] [tbot1.system_health]: CPU usage: max 95 [%] mean 87 [%] RAM usage: 39/59 [MB] Apr 27 12:47:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599647.006091572] [tbot1.system_health]: CPU usage: max 95 [%] mean 87 [%] RAM usage: 39/59 [MB] Apr 27 12:48:15 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 135s Apr 27 12:48:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599707.003533980] [tbot1.system_health]: CPU usage: max 94 [%] mean 88 [%] RAM usage: 38/59 [MB] Apr 27 12:49:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599767.005212373] [tbot1.system_health]: CPU usage: max 96 [%] mean 87 [%] RAM usage: 38/59 [MB] Apr 27 12:50:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599827.003384777] [tbot1.system_health]: CPU usage: max 94 [%] mean 88 [%] RAM usage: 39/59 [MB] Apr 27 12:50:47 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 128s Apr 27 12:50:55 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.007989 is too high, ignoring Apr 27 12:51:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599887.008426802] [tbot1.system_health]: CPU usage: max 96 [%] mean 88 [%] RAM usage: 38/59 [MB] Apr 27 12:52:18 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: Script called in periodic mode Apr 27 12:52:26 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682599946.996181548] [tbot1.system_health]: CPU usage: max 96 [%] mean 89 [%] RAM usage: 38/59 [MB] Apr 27 12:53:11 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 257s Apr 27 12:53:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600006.999449350] [tbot1.system_health]: CPU usage: max 96 [%] mean 89 [%] RAM usage: 38/59 [MB] Apr 27 12:54:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600067.002007255] [tbot1.system_health]: CPU usage: max 94 [%] mean 89 [%] RAM usage: 38/59 [MB] Apr 27 12:55:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600127.004629253] [tbot1.system_health]: CPU usage: max 93 [%] mean 88 [%] RAM usage: 38/59 [MB] Apr 27 12:56:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600187.000124615] [tbot1.system_health]: CPU usage: max 97 [%] mean 88 [%] RAM usage: 39/59 [MB] Apr 27 12:57:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600247.008117633] [tbot1.system_health]: CPU usage: max 95 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 12:57:46 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 258s Apr 27 12:58:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600307.008021798] [tbot1.system_health]: CPU usage: max 98 [%] mean 88 [%] RAM usage: 39/59 [MB] Apr 27 12:59:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600367.009435318] [tbot1.system_health]: CPU usage: max 96 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 13:00:00 iRobot-8748D7279D6349E98FCA76C83EF27D99 cron.info crond[1092]: USER root pid 5688 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp Apr 27 13:00:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600426.999162534] [tbot1.system_health]: CPU usage: max 96 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 13:01:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600487.001391513] [tbot1.system_health]: CPU usage: max 97 [%] mean 88 [%] RAM usage: 39/59 [MB] Apr 27 13:02:21 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 266s Apr 27 13:02:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600547.008370378] [tbot1.system_health]: CPU usage: max 97 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 13:03:06 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600586: New connection from 127.0.0.1 on port 1883. Apr 27 13:03:06 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600586: New client connected from 127.0.0.1 as mosqpub/6142-iRobot-874 (c1, k60). Apr 27 13:03:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600587: Client mosqpub/6142-iRobot-874 disconnected. Apr 27 13:03:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600587: New connection from 127.0.0.1 on port 1883. Apr 27 13:03:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600587: New client connected from 127.0.0.1 as mosqpub/6144-iRobot-874 (c1, k60). Apr 27 13:03:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682600587: Client mosqpub/6144-iRobot-874 disconnected. Apr 27 13:03:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600607.008186404] [tbot1.system_health]: CPU usage: max 97 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:04:18 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.003733 is too high, ignoring Apr 27 13:04:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600667.006047512] [tbot1.system_health]: CPU usage: max 98 [%] mean 92 [%] RAM usage: 39/59 [MB] Apr 27 13:05:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600727.000976747] [tbot1.system_health]: CPU usage: max 97 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 13:06:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600787.004577124] [tbot1.system_health]: CPU usage: max 97 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:07:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 267s Apr 27 13:07:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600847.002195690] [tbot1.system_health]: CPU usage: max 97 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:08:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600907.006821692] [tbot1.system_health]: CPU usage: max 100 [%] mean 96 [%] RAM usage: 39/59 [MB] Apr 27 13:09:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682600967.005306768] [tbot1.system_health]: CPU usage: max 99 [%] mean 96 [%] RAM usage: 39/59 [MB] Apr 27 13:10:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601027.010817031] [tbot1.system_health]: CPU usage: max 98 [%] mean 95 [%] RAM usage: 39/59 [MB] Apr 27 13:11:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601087.004276903] [tbot1.system_health]: CPU usage: max 100 [%] mean 96 [%] RAM usage: 39/59 [MB] Apr 27 13:11:48 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 524s Apr 27 13:12:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601147.001749106] [tbot1.system_health]: CPU usage: max 100 [%] mean 92 [%] RAM usage: 39/59 [MB] Apr 27 13:13:07 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004687 is too high, ignoring Apr 27 13:13:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601207.006989996] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:14:06 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: Script called in periodic mode Apr 27 13:14:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601267.012304468] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:15:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601327.011450082] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:16:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601387.013070969] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:17:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601447.006109914] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:18:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601507.005213284] [tbot1.system_health]: CPU usage: max 100 [%] mean 96 [%] RAM usage: 39/59 [MB] Apr 27 13:19:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601567.021814681] [tbot1.system_health]: CPU usage: max 97 [%] mean 89 [%] RAM usage: 39/59 [MB] Apr 27 13:19:59 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: Server 'ntpd' was stopped gracefully. Apr 27 13:20:01 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601601: New connection from 127.0.0.1 on port 1883. Apr 27 13:20:01 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601601: New client connected from 127.0.0.1 as mosqpub/8631-iRobot-874 (c1, k60). Apr 27 13:20:01 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601601: Client mosqpub/8631-iRobot-874 disconnected. Apr 27 13:20:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601604: New connection from 127.0.0.1 on port 1883. Apr 27 13:20:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601604: New client connected from 127.0.0.1 as mosqpub/8642-iRobot-874 (c1, k60). Apr 27 13:20:04 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601604: Client mosqpub/8642-iRobot-874 disconnected. Apr 27 13:20:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601605: New connection from 127.0.0.1 on port 1883. Apr 27 13:20:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601605: New client connected from 127.0.0.1 as mosqpub/8649-iRobot-874 (c1, k60). Apr 27 13:20:05 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601605: Client mosqpub/8649-iRobot-874 disconnected. Apr 27 13:20:08 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.003203 is too high, ignoring Apr 27 13:20:08 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601608: New connection from 127.0.0.1 on port 1883. Apr 27 13:20:08 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601608: New client connected from 127.0.0.1 as mosqpub/8662-iRobot-874 (c1, k60). Apr 27 13:20:08 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601608: Client mosqpub/8662-iRobot-874 disconnected. Apr 27 13:20:11 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601611: New connection from 127.0.0.1 on port 1883. Apr 27 13:20:12 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601611: New client connected from 127.0.0.1 as mosqpub/8673-iRobot-874 (c1, k60). Apr 27 13:20:12 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601612: Client mosqpub/8673-iRobot-874 disconnected. Apr 27 13:20:16 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 33s Apr 27 13:20:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601627.006926519] [tbot1.system_health]: CPU usage: max 100 [%] mean 84 [%] RAM usage: 39/59 [MB] Apr 27 13:21:06 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 33s Apr 27 13:21:16 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601676: New connection from 127.0.0.1 on port 1883. Apr 27 13:21:16 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601676: New client connected from 127.0.0.1 as mosqpub/8832-iRobot-874 (c1, k60). Apr 27 13:21:16 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601676: Client mosqpub/8832-iRobot-874 disconnected. Apr 27 13:21:17 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.009556 is too high, ignoring Apr 27 13:21:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601687.016088787] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:21:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601709: New connection from 127.0.0.1 on port 1883. Apr 27 13:21:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601709: New client connected from 127.0.0.1 as mosqpub/8915-iRobot-874 (c1, k60). Apr 27 13:21:49 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice mosquitto: 1682601709: Client mosqpub/8915-iRobot-874 disconnected. Apr 27 13:21:56 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 67s Apr 27 13:22:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601747.014090668] [tbot1.system_health]: CPU usage: max 98 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:23:20 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 65s Apr 27 13:23:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601807.019770928] [tbot1.system_health]: CPU usage: max 96 [%] mean 92 [%] RAM usage: 39/59 [MB] Apr 27 13:24:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601867.008550244] [tbot1.system_health]: CPU usage: max 97 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:24:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 64s Apr 27 13:25:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601927.013077040] [tbot1.system_health]: CPU usage: max 98 [%] mean 91 [%] RAM usage: 39/59 [MB] Apr 27 13:26:03 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 67s Apr 27 13:26:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682601987.027975792] [tbot1.system_health]: CPU usage: max 100 [%] mean 96 [%] RAM usage: 39/59 [MB] Apr 27 13:26:41 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.002534 is too high, ignoring Apr 27 13:27:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682602047.028898808] [tbot1.system_health]: CPU usage: max 100 [%] mean 100 [%] RAM usage: 39/59 [MB] Apr 27 13:27:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice ntpd: ntpd: timed out waiting for 192.168.186.1, reach 0x00, next query in 130s Apr 27 13:28:27 iRobot-8748D7279D6349E98FCA76C83EF27D99 user.notice create-platform: [INFO] [1682602107.017764002] [tbot1.system_health]: CPU usage: max 98 [%] mean 93 [%] RAM usage: 39/59 [MB]

Other notes
I thought this was a time sync issue, so I tried running turtlebot4-ntpd-sync but that did not help.

[roni-kreinin]

This is likely related to the 100% CPU usage. It can cause significant delays in messages being published which is probably causing tf to drop them.

The issue is being tracked here.