Kanazawanaoaki
commented
1 year ago 先程もpr1040でこの問題と同じようにサーボが入らない事態が発生しました．一時的な解決策としては，やはり(本当に効果があるかは未検証だが)pr2の腕を動かすなどして暫くするとサーボが入るようになるようです．
まだ原因や解決策を解明できた訳ではないので，分かっている情報をなるべく整理して記しておきます．
ログなど：https://gist.github.com/Kanazawanaoaki/206e1ef6452711b7d648b1e7f556bac5
症状の整理
サーボが入らなくなる時の症状としては，
audible warningでrealtime controllers realtime control loop realtime loop used too much time in the last 30 seconds.;が出ている．(hzのwarningだけの時はサーボが入る)robot.logに[ERROR] [1664324590.399660822] [/realtime_loop:ros.ethercat_hardware]: Device 16 : previous port error counters less current valuesのようなエラーが出ている- EtherCATの
rx errorが発生している
の3つの症状が発生しているようです．それぞれの関係性と原因についてはまだ良くわかっていません．
audible warning で realtime controllers realtime control loop realtime loop used too much time in the last 30 seconds.; が出ている．
2022年の9月に入ってからpr1040でRealtime loopが遅くなり audible warning で以下のようなwarningが出ることが報告されるようになった．https://github.com/jsk-ros-pkg/jsk_robot/issues/1623
[INFO] [1664417978.378555] [/audible_warning:rosout]: audible warning talking: error. realtime controllers realtime control loop halting, realtime loop only ran at 740.0000 hzさらにrealtime controllers realtime control loop realtime loop used too much time in the last 30 seconds.; が同時に表示されていることがある．
[INFO] [1665932713.034740] [/audible_warning:rosout]: audible warning talking: error. realtime controllers realtime control loop realtime loop used too much time in the last 30 seconds.; halting, realtime loop only ran at 740.0000 hzこのようなwarningの場合はサーボを入れるとwarningが出なくなる（しばらくすると再発することもある）ことが報告されています https://github.com/jsk-ros-pkg/jsk_robot/issues/1623#issuecomment-1267112863 ． 確かに昨日のログでも今日のログでもランストップを押してサーボを入れるとそれまで連続していたwarningが出なくなっている．
これは，https://github.com/jsk-ros-pkg/jsk_robot/issues/1623#issuecomment-1267150609 で言われているように
- サーボOFF状態だと、このwarningが出てもHzが更新されず、同じHzのwarningが出続ける
- サーボON状態だと、Hzが更新されているようで、warningが出たり消えたりする
ということのようである．
しかし，以下のようにrealtime loop used too much time in the last 30 secondのwarningも出ている時にランストップを入れるとサーボが入らないようである．（昨日の該当箇所のログ，今日の該当箇所のログ）
[INFO] [1664309197.368809] [/audible_warning:rosout]: audible warning talking: error. realtime controllers realtime control loop realtime loop used too much time in the last 30 seconds.; halting, realtime loop only ran at 740.0000 hzこれまでもhzのwarningとtoo muchのwarningが一緒に出ていたことはあるようだが，そのタイミングでサーボを入れていなかったからこの問題が発生しなかっただけ？
調査
この情報で検索してhitしたのは以下の2つ. 詳しくみる必要があるかも．
- https://groups.google.com/g/pr2_users/c/cqaRPAkeino
- https://github.com/tork-a/minas/blob/4ff346d334078f2958222024accb07499c6d66d9/minas_control/src/main.cpp#L203
robot.log に [ERROR] [1664324590.399660822] [/realtime_loop:ros.ethercat_hardware]: Device 16 : previous port error counters less current valuesのようなエラーが出ている
よく調べていくと昨日のログには
readMailboxInternal : [43mERROR[0m asking for read repeat after dropping 1 packetsだけではなく，以下のエラーログも出ていた．今日のログにもDevice の番号は違うが出ていたので，これがサーボがつかない直接的な原因かもしれない．
[31m[ERROR] [1665826174.272734993] [/realtime_loop:ros.ethercat_hardware]: Device 16 : previous port error counters less current values[0m調査
このエラーログはPR2/pr2_ethercat_driversで出されているものだということは分かった．
https://github.com/PR2/pr2_ethercat_drivers/blob/d93eb53a0a3a8e6706f7061e30e37a5d021eee1d/ethercat_hardware/src/ethercat_device.cpp#L245-L247
EtherCATの rx error が発生している
https://github.com/jsk-ros-pkg/jsk_robot/issues/1671#issue-1410142269 でも報告した通り，rx errorが発生している時にサーボが入らなくなり，サーボが安定している時にはrx errorは増えていない．これが根本の原因の可能性もある．
$ rosrun jsk_pr2_startup diagnostics_rx_error_summarizer.py
/Motors/EtherCAT Device #00 (WG014) RX Error Port 0: 0
/Motors/EtherCAT Device #00 (WG014) RX Error Port 1: 0
/Motors/EtherCAT Device #00 (WG014) RX Error Port 2: 0
/Motors/EtherCAT Device #00 (WG014) RX Error Port 3: 0
/Motors/EtherCAT Device #01 (WG014) RX Error Port 0: 0
/Motors/EtherCAT Device #01 (WG014) RX Error Port 1: 0
/Motors/EtherCAT Device #01 (WG014) RX Error Port 2: 0
/Motors/EtherCAT Device #01 (WG014) RX Error Port 3: 0
/Motors/EtherCAT Device #15 (WG014) RX Error Port 0: 0
/Motors/EtherCAT Device #15 (WG014) RX Error Port 1: 0
/Motors/EtherCAT Device #15 (WG014) RX Error Port 2: 0
/Motors/EtherCAT Device #15 (WG014) RX Error Port 3: 0
/Motors/EtherCAT Device #16 (WG014) RX Error Port 0: 0
/Motors/EtherCAT Device #16 (WG014) RX Error Port 1: 0
/Motors/EtherCAT Device #16 (WG014) RX Error Port 2: 0
/Motors/EtherCAT Device #16 (WG014) RX Error Port 3: 0
/Motors/EtherCAT Device (bl_caster_l_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (bl_caster_l_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (bl_caster_r_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (bl_caster_r_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (bl_caster_rotation_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (bl_caster_rotation_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (br_caster_l_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (br_caster_l_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (br_caster_r_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (br_caster_r_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (br_caster_rotation_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (br_caster_rotation_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fl_caster_l_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fl_caster_l_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fl_caster_r_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fl_caster_r_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fl_caster_rotation_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fl_caster_rotation_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fr_caster_l_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fr_caster_l_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fr_caster_r_wheel_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fr_caster_r_wheel_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (fr_caster_rotation_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (fr_caster_rotation_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (head_pan_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (head_pan_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (head_tilt_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (head_tilt_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_elbow_flex_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_elbow_flex_motor) RX Error Port 1: 208261
/Motors/EtherCAT Device (l_forearm_roll_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_forearm_roll_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_gripper_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_shoulder_lift_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_shoulder_lift_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_shoulder_pan_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_shoulder_pan_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_upper_arm_roll_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_upper_arm_roll_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_wrist_l_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_wrist_l_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (l_wrist_r_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (l_wrist_r_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (laser_tilt_mount_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (laser_tilt_mount_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (led_projector) RX Error Port 0: 0
/Motors/EtherCAT Device (led_projector) RX Error Port 1: 0
/Motors/EtherCAT Device (r_elbow_flex_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_elbow_flex_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_forearm_roll_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_forearm_roll_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_gripper_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_shoulder_lift_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_shoulder_lift_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_shoulder_pan_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_shoulder_pan_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_upper_arm_roll_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_upper_arm_roll_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_wrist_l_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_wrist_l_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (r_wrist_r_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (r_wrist_r_motor) RX Error Port 1: 0
/Motors/EtherCAT Device (torso_lift_motor) RX Error Port 0: 0
/Motors/EtherCAT Device (torso_lift_motor) RX Error Port 1: 0
/Motors/EtherCAT Master RX Errors: 288952
[Max Device]
/Motors/EtherCAT Device (l_elbow_flex_motor) RX Error Port 1: 208261Forwarded 以外の RX Error Port でみると，やはり l_elbow_flex_motor でエラーがおきているように思える．サーボが復活した時にはMasterもl_elbow_flex_motorもrx errorが上がらなくなった．
調査
/Motors/EtherCAT Master RX Errorsが何を示しているか等は不明．RX Error Portの合計値という訳でも無い．しかしethtool -S ecat0したときのrx_crc_errorsとrx_frame_errorsの値の合計がrx_errorsになっている．
(rx_errors) = (rx_crc_errors) + (rx_frame_errors)ちなみに関連していそうな話題としてEtherCAT Masterにおいてros wiki に載っている以下の関係式があるが RX Errorとの関連性は不明．値は微妙に一致していない．．．
(Dropped Packets) = (CRC Errors) + (RX Late Packet)値の一覧
rx_errors: 460752
rx_crc_errors: 230412
rx_frame_errors: 230340Dropped Packets: 154664
RX Late Packet: 8
CRC Errors (Dropped Packets - RX Late Packet): 154656
k-okada
pr1040でサーボが入らなくなる(入ってもガクガクする)問題が発生し，原因を調べた所，https://github.com/jsk-ros-pkg/jsk_robot/issues/794 と同じようにrx errorが多くなっていました．
原因特定の経緯
pr1040が暫くaudible warningでrealtime loopについて喋っていたのでサーボを入れてみたが入らなかった．（realtime loopのwarningは一度サーボを入れると無くなるという情報有り？要出典調査）
のログをみると2022/10/15 14:36:54 あたりから
のようなwarningを喋っていたよう．
rqt_pr2_dashboardを見ると，モーターではパケットドロップしていないがMasterではドロップしている．
(時々 “Could not collect WG0X diagnostics” のようなメッセージも出ている)
robotのログを見ると
が出ている．これを検索すると以下のpr1012でのEtherCATのNICでrx errorが多いというissueがhit． https://github.com/jsk-ros-pkg/jsk_robot/issues/794 issueを見るとこれ自体はサーボが入らなくなる様なエラーでは無い気がするが，issueで出てきている
ethtool -S ecat0を試してみるとrx_errorsが多かった．※ログが流れてしまったので，後ほど20:01時点で実行した結果，
issueで報告されているpr1040の値は rx_errors: 4 なのでとても多くなっている．
rx_errorsをcountするscriptで確認．出力されたcsvファイルを見ると，l_elbow_flex_motorのRX Error Port 1の値が大きく，上昇もしているので怪しい．
rqt_pr2_dashboardでl_elbow_flex_motorのDropsを確認したが0だった．
一時的な解決
upstartのrobotを立ち上げ直したが改善しなかった．（因果関係は定かでないが）左腕を少し動かしてサーボを何度か入れてみたがサーボが上手くはいらずガクガクしている状態だった．しばらく放置して確認作業をしている間にサーボが復活していた．
復活した後のrx_errorのcsvを見ると，l_elbow_flex_motorのRX Error Port 1の値は固定値で上がっていない，やはりこれが今回の原因なのか？
今後の対策
l_elbow_flex_motor周りのケーブル交換等が必要？