{"action":"opened","issue":{"url":"https://api.github.com/repos/tue-robotics/tue_robocup/issues/46","labels_url":"https://api.github.com/repos/tue-robotics/tue_robocup/issues/46/labels{/name}","comments_url":"https://api.github.com/repos/tue-robotics/tue_robocup/issues/46/comments","events_url":"https://api.github.com/repos/tue-robotics/tue_robocup/issues/46/events","html_url":"https://github.com/tue-robotics/tue_robocup/issues/46","id":67088442,"number":46,"title":"challange_manipulation test","user":{"login":"TonPeters","id":8795739,"avatar_url":"https://avatars.githubusercontent.com/u/8795739?v=3","gravatar_id":"","url":"https://api.github.com/users/TonPeters","html_url":"https://github.com/TonPeters","followers_url":"https://api.github.com/users/TonPeters/followers","following_url":"https://api.github.com/users/TonPeters/following{/other_user}","gists_url":"https://api.github.com/users/TonPeters/gists{/gist_id}","starred_url":"https://api.github.com/users/TonPeters/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/TonPeters/subscriptions","organizations_url":"https://api.github.com/users/TonPeters/orgs","repos_url":"https://api.github.com/users/TonPeters/repos","events_url":"https://api.github.com/users/TonPeters/events{/privacy}","received_events_url":"https://api.github.com/users/TonPeters/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":0,"created_at":"2015-04-08T09:28:33Z","updated_at":"2015-04-08T09:28:33Z","closed_at":null,"body":"Errors:\r\n- Amigo is not always able to navigate to the bookcase and in this case it detects objects outside of the bookcase.\r\n- When it is able to drive to the bookcase it cannot grasp the objects it detects, see below for the terminal output:\r\n\r\namigo@amigo3 $ rosrun challenge_manipulation manipulation.py amigo\r\n[INFO] [WallTime: 1428484489.070069] Using robot 'amigo'.\r\nIf you want to test an executive, use the --test option and specify what parts you want to mock.\r\n[WARN] [WallTime: 1428484489.087757] Nav_analyser: Bagging = False\r\n[INFO] [WallTime: 1428484489.090326] Waiting for the global planner services ...\r\n[INFO] [WallTime: 1428484489.763302] Waiting for service /amigo/text_to_speech/speak\r\n[INFO] [WallTime: 1428484489.767326] Initializing ebutton listener\r\nEdEntityDesignator(robot, type=, center_point=x: 0.0 y: 0.0 z: 0.0, radius=0, id=plastic_cabinet_shelf_1, parse=True, criteriafuncs=[]) = pick_shelf\r\n<robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c550> = current_item\r\n<robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c5d0> = place_position\r\n<robot_smach_states.util.designators.designator.UnoccupiedArmDesignator object at 0x332c610> = empty_arm_designator\r\n<robot_smach_states.util.designators.designator.ArmHoldingEntityDesignator object at 0x332c650> = arm_with_item_designator\r\n[INFO] [WallTime: 1428484489.830443] State machine starting in initial state 'INITIALIZE' with userdata: \r\n\t[]\r\n[WARN] [WallTime: 1428484489.841187] ToDo: Close grippers\r\n[WARN] [WallTime: 1428484490.853921] ToDo: Reset costmap and reasoner\r\n[INFO] [WallTime: 1428484490.854809] TF link between /map and /base_link is checked. If it takes longer than a second, probably an error. Do a restart!!!\r\n[WARN] [WallTime: 1428484490.860301] ToDo: Load correct perception config???\r\n[INFO] [WallTime: 1428484490.861279] State machine transitioning 'INITIALIZE':'initialized'-->'AWAIT_START'\r\n[INFO] [WallTime: 1428484490.862376] State machine starting in initial state 'SAY' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484490.863410] 'I will wait until you say continue.'\r\n[INFO] [WallTime: 1428484494.235748] State machine transitioning 'SAY':'spoken'-->'HEAR'\r\n[INFO] [WallTime: 1428484497.822025] State machine terminating 'HEAR':'heard':'continue'\r\n[INFO] [WallTime: 1428484497.822375] State machine transitioning 'AWAIT_START':'continue'-->'NAV_TO_START'\r\n[INFO] [WallTime: 1428484497.822795] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484497.825884] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484497.826334] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[ERROR] [WallTime: 1428484497.952822] Called get_state when no goal is running\r\n[INFO] [WallTime: 1428484497.953815] State machine terminating 'GET_PLAN':'unreachable':'unreachable'\r\n[INFO] [WallTime: 1428484497.954610] State machine transitioning 'NAVIGATE':'unreachable'-->'STOP_ANALYSIS_UNREACHABLE'\r\n[INFO] [WallTime: 1428484497.961393] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 0.134780883789 seconds (0.0) m/s avg.\r\nResult = unreachable with 0 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484497.962386] State machine terminating 'STOP_ANALYSIS_UNREACHABLE':'done':'unreachable'\r\n[INFO] [WallTime: 1428484497.963151] State machine transitioning 'NAV_TO_START':'unreachable'-->'RANGE_ITERATOR'\r\n[INFO] [WallTime: 1428484497.964122] Iterating 0 of <function <lambda> at 0x32fd230>\r\n[INFO] [WallTime: 1428484497.965119] State machine starting in initial state 'NAV_TO_OBSERVE_PICK_SHELF' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484497.966027] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484497.972106] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484497.973255] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[ERROR] [WallTime: 1428484498.183520] Called get_state when no goal is running\r\n[INFO] [WallTime: 1428484498.184061] State machine terminating 'GET_PLAN':'unreachable':'unreachable'\r\n[INFO] [WallTime: 1428484498.184531] State machine transitioning 'NAVIGATE':'unreachable'-->'STOP_ANALYSIS_UNREACHABLE'\r\n[INFO] [WallTime: 1428484498.189020] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 0.216989994049 seconds (0.0) m/s avg.\r\nResult = unreachable with 0 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484498.189558] State machine terminating 'STOP_ANALYSIS_UNREACHABLE':'done':'unreachable'\r\n[INFO] [WallTime: 1428484498.190014] State machine transitioning 'NAV_TO_OBSERVE_PICK_SHELF':'unreachable'-->'LOOKAT_PICK_SHELF'\r\n[INFO] [WallTime: 1428484498.190698] 'I'm looking at the pick shelf to see what items I can find'\r\n[INFO] [WallTime: 1428484502.842811] State machine transitioning 'LOOKAT_PICK_SHELF':'spoken'-->'LOCK_ITEM'\r\n[INFO] [WallTime: 1428484503.440341] <robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c550> locked to id: 4a1699\r\n[INFO] [WallTime: 1428484503.440685] Current_item is now locked to 4a16993d03c638317dce901b28ac6c4b\r\n[INFO] [WallTime: 1428484503.440967] State machine transitioning 'LOCK_ITEM':'locked'-->'ANNOUNCE_ITEM'\r\n[INFO] [WallTime: 1428484503.441448] 'I'm trying to grab item 4a169 which is a beer.'\r\n[INFO] [WallTime: 1428484503.443783] State machine transitioning 'ANNOUNCE_ITEM':'spoken'-->'GRAB_ITEM'\r\n[INFO] [WallTime: 1428484503.444200] State machine starting in initial state 'NAVIGATE_TO_GRAB' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484503.444528] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484503.447374] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484503.447807] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484503.548336] Navigating to grasp entity id:4a16993d03c638317dce901b28ac6c4b\r\n[ERROR] [WallTime: 1428484503.558221] Called get_state when no goal is running\r\n[INFO] [WallTime: 1428484503.558565] State machine terminating 'GET_PLAN':'unreachable':'unreachable'\r\n[INFO] [WallTime: 1428484503.558822] State machine transitioning 'NAVIGATE':'unreachable'-->'STOP_ANALYSIS_UNREACHABLE'\r\n[INFO] [WallTime: 1428484503.562134] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 0.114650011063 seconds (0.0) m/s avg.\r\nResult = unreachable with 0 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484503.562466] State machine terminating 'STOP_ANALYSIS_UNREACHABLE':'done':'unreachable'\r\n[INFO] [WallTime: 1428484503.562748] State machine terminating 'NAVIGATE_TO_GRAB':'unreachable':'failed'\r\n[INFO] [WallTime: 1428484503.563002] State machine transitioning 'GRAB_ITEM':'failed'-->'SAY_GRAB_FAILED'\r\n[INFO] [WallTime: 1428484503.563309] 'I couldn't grab this thing'\r\n[INFO] [WallTime: 1428484510.716468] State machine transitioning 'SAY_GRAB_FAILED':'spoken'-->'UNLOCK_ITEM_AFTER_FAILED_GRAB'\r\n[INFO] [WallTime: 1428484510.718245] Current_item WAS now locked to 4a16993d03c638317dce901b28ac6c4b\r\n[INFO] [WallTime: 1428484510.719054] State machine terminating 'UNLOCK_ITEM_AFTER_FAILED_GRAB':'unlocked':'failed'\r\n[INFO] [WallTime: 1428484510.720049] Iterating 1 of <function <lambda> at 0x32fd230>\r\n[INFO] [WallTime: 1428484510.720958] State machine starting in initial state 'NAV_TO_OBSERVE_PICK_SHELF' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484510.721931] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484510.728561] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484510.729849] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484510.986817] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x31dc9e0>\r\n[INFO] [WallTime: 1428484510.987722] 'Getting there!'\r\n[INFO] [WallTime: 1428484510.991815] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484511.026396] Received comm state RECALLING when in simple state DONE with SimpleActionClient in NS /amigo/head_ref/action_server\r\n[INFO] [WallTime: 1428484520.053755] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484520.054858] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484520.062282] \r\n\r\nNavigation summary:\r\nCovered 0.745106606375 meters in 9.3333261013 seconds (0.0798329125424) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484520.063265] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484520.064046] State machine transitioning 'NAV_TO_OBSERVE_PICK_SHELF':'arrived'-->'LOOKAT_PICK_SHELF'\r\n[INFO] [WallTime: 1428484520.065271] 'I'm looking at the pick shelf to see what items I can find'\r\n[INFO] [WallTime: 1428484524.718088] State machine transitioning 'LOOKAT_PICK_SHELF':'spoken'-->'LOCK_ITEM'\r\n[INFO] [WallTime: 1428484525.947297] choosing best entity from this list (name->weight):\r\n\t[('bc09ef59d2a039bcf306ac2192cfe46a', 1.3071554373534662), ('680beeb4eec83d72824841a0f3360187', 0.8101014035289827), ('1f59e1fbadd021fb968376cb7c0a5c77', 0.6625950100471968)]\r\n[INFO] [WallTime: 1428484525.957216] <robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c550> locked to id: 1f59e1\r\n[INFO] [WallTime: 1428484525.957680] Current_item is now locked to 1f59e1fbadd021fb968376cb7c0a5c77\r\n[INFO] [WallTime: 1428484525.958104] State machine transitioning 'LOCK_ITEM':'locked'-->'ANNOUNCE_ITEM'\r\n[INFO] [WallTime: 1428484525.958772] 'I'm trying to grab item 1f59e which is a cup.'\r\n[INFO] [WallTime: 1428484525.962358] State machine transitioning 'ANNOUNCE_ITEM':'spoken'-->'GRAB_ITEM'\r\n[INFO] [WallTime: 1428484525.963222] State machine starting in initial state 'NAVIGATE_TO_GRAB' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484525.963945] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484525.970536] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484525.972013] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484526.072858] Navigating to grasp entity id:1f59e1fbadd021fb968376cb7c0a5c77\r\n[INFO] [WallTime: 1428484526.082617] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x33cc638>\r\n[INFO] [WallTime: 1428484526.082976] 'Getting there!'\r\n[INFO] [WallTime: 1428484526.085768] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484526.146782] Received comm state RECALLING when in simple state DONE with SimpleActionClient in NS /amigo/head_ref/action_server\r\n[INFO] [WallTime: 1428484529.117108] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484529.118110] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484529.132208] \r\n\r\nNavigation summary:\r\nCovered 0.265769846785 meters in 3.16223216057 seconds (0.0840450141829) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484529.133326] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484529.134095] State machine transitioning 'NAVIGATE_TO_GRAB':'arrived'-->'GRAB'\r\n[INFO] [WallTime: 1428484529.135159] PickUp!\r\n[INFO] [WallTime: 1428484529.140870] x: 0.620734738863\r\ny: 0.191563249496\r\nz: 1.13257431984\r\n[ERROR] [WallTime: 1428484531.426969] SimpleActionClient received DONE twice\r\n[INFO] [WallTime: 1428484533.461936] Starting Pre-grasp\r\n[ERROR] [WallTime: 1428484533.568174] grasp precompute goal failed: \r\n{'pz': 1.1325743198394775, 'roll': 0, 'pre_grasp': True, 'py': 0.19156324949644832, 'first_joint_pos_only': True, 'self': <robot_skills.arms.Arm object at 0x3308050>, 'frame_id': '/amigo/base_link', 'allowed_touch_objects': [], 'timeout': 20, 'pitch': 0, 'px': 0.6207347388633089, 'yaw': 0}\r\n[ERROR] [WallTime: 1428484533.569175] Pre-grasp failed:\r\n[INFO] [WallTime: 1428484533.578627] State machine terminating 'GRAB':'failed':'failed'\r\n[INFO] [WallTime: 1428484533.579428] State machine transitioning 'GRAB_ITEM':'failed'-->'SAY_GRAB_FAILED'\r\n[INFO] [WallTime: 1428484533.581176] 'I couldn't grab this thing'\r\n[INFO] [WallTime: 1428484535.929389] State machine transitioning 'SAY_GRAB_FAILED':'spoken'-->'UNLOCK_ITEM_AFTER_FAILED_GRAB'\r\n[INFO] [WallTime: 1428484535.931032] Current_item WAS now locked to 1f59e1fbadd021fb968376cb7c0a5c77\r\n[INFO] [WallTime: 1428484535.932557] State machine terminating 'UNLOCK_ITEM_AFTER_FAILED_GRAB':'unlocked':'failed'\r\n[INFO] [WallTime: 1428484535.933774] Iterating 2 of <function <lambda> at 0x32fd230>\r\n[INFO] [WallTime: 1428484535.934807] State machine starting in initial state 'NAV_TO_OBSERVE_PICK_SHELF' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484535.935957] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484535.942094] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484535.943420] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484536.199828] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x33cc518>\r\n[INFO] [WallTime: 1428484536.200362] 'Getting there!'\r\n[INFO] [WallTime: 1428484536.204016] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484536.226372] SimpleActionClient received DONE twice\r\n[INFO] [WallTime: 1428484540.233412] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484540.234360] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484540.241419] \r\n\r\nNavigation summary:\r\nCovered 0.0642518689438 meters in 4.29851794243 seconds (0.0149474469583) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484540.242663] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484540.244050] State machine transitioning 'NAV_TO_OBSERVE_PICK_SHELF':'arrived'-->'LOOKAT_PICK_SHELF'\r\n[INFO] [WallTime: 1428484540.245979] 'I'm looking at the pick shelf to see what items I can find'\r\n[INFO] [WallTime: 1428484544.902345] State machine transitioning 'LOOKAT_PICK_SHELF':'spoken'-->'LOCK_ITEM'\r\n[INFO] [WallTime: 1428484546.011625] choosing best entity from this list (name->weight):\r\n\t[('bc09ef59d2a039bcf306ac2192cfe46a', 0.812023885493317), ('680beeb4eec83d72824841a0f3360187', 0.4344541556440051)]\r\n[INFO] [WallTime: 1428484546.016602] <robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c550> locked to id: 680bee\r\n[INFO] [WallTime: 1428484546.016884] Current_item is now locked to 680beeb4eec83d72824841a0f3360187\r\n[INFO] [WallTime: 1428484546.017233] State machine transitioning 'LOCK_ITEM':'locked'-->'ANNOUNCE_ITEM'\r\n[INFO] [WallTime: 1428484546.017787] 'I'm trying to grab item 680be which is a chewing gum white.'\r\n[INFO] [WallTime: 1428484546.020478] State machine transitioning 'ANNOUNCE_ITEM':'spoken'-->'GRAB_ITEM'\r\n[INFO] [WallTime: 1428484546.020992] State machine starting in initial state 'NAVIGATE_TO_GRAB' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484546.021425] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484546.024829] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484546.025502] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484546.126454] Navigating to grasp entity id:680beeb4eec83d72824841a0f3360187\r\n[INFO] [WallTime: 1428484546.136279] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x33c1c20>\r\n[INFO] [WallTime: 1428484546.136572] 'I'm on my way!'\r\n[INFO] [WallTime: 1428484546.139145] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484546.226031] Received comm state RECALLING when in simple state DONE with SimpleActionClient in NS /amigo/head_ref/action_server\r\n[INFO] [WallTime: 1428484547.146546] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484547.147781] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484547.156689] \r\n\r\nNavigation summary:\r\nCovered 0.0398377976706 meters in 1.13009619713 seconds (0.0352516872209) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484547.157960] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484547.158824] State machine transitioning 'NAVIGATE_TO_GRAB':'arrived'-->'GRAB'\r\n[INFO] [WallTime: 1428484547.159951] PickUp!\r\n[INFO] [WallTime: 1428484547.165272] x: 0.624605718762\r\ny: 0.18787482616\r\nz: 1.10768961906\r\n[ERROR] [WallTime: 1428484551.346924] SimpleActionClient received DONE twice\r\n[INFO] [WallTime: 1428484551.386337] Starting Pre-grasp\r\n[ERROR] [WallTime: 1428484551.405385] grasp precompute goal failed: \r\n{'pz': 1.1076896190643315, 'roll': 0, 'pre_grasp': True, 'py': 0.18787482615962636, 'first_joint_pos_only': True, 'self': <robot_skills.arms.Arm object at 0x3308050>, 'frame_id': '/amigo/base_link', 'allowed_touch_objects': [], 'timeout': 20, 'pitch': 0, 'px': 0.6246057187623513, 'yaw': 0}\r\n[ERROR] [WallTime: 1428484551.406651] Pre-grasp failed:\r\n[INFO] [WallTime: 1428484551.412374] State machine terminating 'GRAB':'failed':'failed'\r\n[INFO] [WallTime: 1428484551.413830] State machine transitioning 'GRAB_ITEM':'failed'-->'SAY_GRAB_FAILED'\r\n[INFO] [WallTime: 1428484551.415086] 'I couldn't grab this thing'\r\n[INFO] [WallTime: 1428484556.063707] State machine transitioning 'SAY_GRAB_FAILED':'spoken'-->'UNLOCK_ITEM_AFTER_FAILED_GRAB'\r\n[INFO] [WallTime: 1428484556.065019] Current_item WAS now locked to 680beeb4eec83d72824841a0f3360187\r\n[INFO] [WallTime: 1428484556.065736] State machine terminating 'UNLOCK_ITEM_AFTER_FAILED_GRAB':'unlocked':'failed'\r\n[INFO] [WallTime: 1428484556.066650] Iterating 3 of <function <lambda> at 0x32fd230>\r\n[INFO] [WallTime: 1428484556.067512] State machine starting in initial state 'NAV_TO_OBSERVE_PICK_SHELF' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484556.068339] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484556.072558] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484556.072954] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484556.291730] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x3152cb0>\r\n[INFO] [WallTime: 1428484556.292682] 'Getting there!'\r\n[INFO] [WallTime: 1428484556.298800] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484556.425850] Received comm state RECALLING when in simple state DONE with SimpleActionClient in NS /amigo/head_ref/action_server\r\n[INFO] [WallTime: 1428484557.307175] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484557.308912] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484557.315804] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 1.24208903313 seconds (0.0) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484557.316906] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484557.317764] State machine transitioning 'NAV_TO_OBSERVE_PICK_SHELF':'arrived'-->'LOOKAT_PICK_SHELF'\r\n[INFO] [WallTime: 1428484557.318971] 'I'm looking at the pick shelf to see what items I can find'\r\n[INFO] [WallTime: 1428484563.080141] State machine transitioning 'LOOKAT_PICK_SHELF':'spoken'-->'LOCK_ITEM'\r\n[INFO] [WallTime: 1428484564.094104] <robot_smach_states.util.designators.designator.LockingDesignator object at 0x332c550> locked to id: bc09ef\r\n[INFO] [WallTime: 1428484564.094415] Current_item is now locked to bc09ef59d2a039bcf306ac2192cfe46a\r\n[INFO] [WallTime: 1428484564.094675] State machine transitioning 'LOCK_ITEM':'locked'-->'ANNOUNCE_ITEM'\r\n[INFO] [WallTime: 1428484564.095078] 'I'm trying to grab item bc09e which is a chewing gum white.'\r\n[INFO] [WallTime: 1428484564.097625] State machine transitioning 'ANNOUNCE_ITEM':'spoken'-->'GRAB_ITEM'\r\n[INFO] [WallTime: 1428484564.098155] State machine starting in initial state 'NAVIGATE_TO_GRAB' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484564.098586] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484564.102155] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484564.102792] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484564.203340] Navigating to grasp entity id:bc09ef59d2a039bcf306ac2192cfe46a\r\n[INFO] [WallTime: 1428484564.214535] State machine terminating 'GET_PLAN':'unreachable':'unreachable'\r\n[INFO] [WallTime: 1428484564.214804] State machine transitioning 'NAVIGATE':'unreachable'-->'STOP_ANALYSIS_UNREACHABLE'\r\n[INFO] [WallTime: 1428484564.218031] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 0.115889072418 seconds (0.0) m/s avg.\r\nResult = unreachable with 0 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484564.218292] State machine terminating 'STOP_ANALYSIS_UNREACHABLE':'done':'unreachable'\r\n[INFO] [WallTime: 1428484564.218493] State machine terminating 'NAVIGATE_TO_GRAB':'unreachable':'failed'\r\n[INFO] [WallTime: 1428484564.218678] State machine transitioning 'GRAB_ITEM':'failed'-->'SAY_GRAB_FAILED'\r\n[INFO] [WallTime: 1428484564.218997] 'I couldn't grab this thing'\r\n[INFO] [WallTime: 1428484571.870758] State machine transitioning 'SAY_GRAB_FAILED':'spoken'-->'UNLOCK_ITEM_AFTER_FAILED_GRAB'\r\n[INFO] [WallTime: 1428484571.872014] Current_item WAS now locked to bc09ef59d2a039bcf306ac2192cfe46a\r\n[INFO] [WallTime: 1428484571.873029] State machine terminating 'UNLOCK_ITEM_AFTER_FAILED_GRAB':'unlocked':'failed'\r\n[INFO] [WallTime: 1428484571.874015] Iterating 4 of <function <lambda> at 0x32fd230>\r\n[INFO] [WallTime: 1428484571.874925] State machine starting in initial state 'NAV_TO_OBSERVE_PICK_SHELF' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484571.875956] State machine starting in initial state 'START_ANALYSIS' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484571.881840] State machine transitioning 'START_ANALYSIS':'done'-->'NAVIGATE'\r\n[INFO] [WallTime: 1428484571.883159] State machine starting in initial state 'GET_PLAN' with userdata: \r\n\t[]\r\n[INFO] [WallTime: 1428484572.078172] Goal handle = <actionlib.action_client.ClientGoalHandle instance at 0x37153f8>\r\n[INFO] [WallTime: 1428484572.078563] 'Getting there!'\r\n[INFO] [WallTime: 1428484572.081015] State machine transitioning 'GET_PLAN':'goal_ok'-->'EXECUTE_PLAN'\r\n[ERROR] [WallTime: 1428484572.226001] Received comm state RECALLING when in simple state DONE with SimpleActionClient in NS /amigo/head_ref/action_server\r\n[INFO] [WallTime: 1428484573.085927] State machine terminating 'EXECUTE_PLAN':'succeeded':'arrived'\r\n[INFO] [WallTime: 1428484573.086256] State machine transitioning 'NAVIGATE':'arrived'-->'STOP_ANALYSIS_SUCCEED'\r\n[INFO] [WallTime: 1428484573.089531] \r\n\r\nNavigation summary:\r\nCovered 0.0 meters in 1.20791220665 seconds (0.0) m/s avg.\r\nResult = succeeded with 1 plans, 0 clears and 0 resets\r\n\r\n\r\n[INFO] [WallTime: 1428484573.089861] State machine terminating 'STOP_ANALYSIS_SUCCEED':'done':'arrived'\r\n[INFO] [WallTime: 1428484573.090144] State machine transitioning 'NAV_TO_OBSERVE_PICK_SHELF':'arrived'-->'LOOKAT_PICK_SHELF'\r\n[INFO] [WallTime: 1428484573.090581] 'I'm looking at the pick shelf to see what items I can find'\r\n^C[ERROR] [WallTime: 1428484576.639148] InvalidUserCodeError: Could not execute state 'LOOKAT_PICK_SHELF' of type '<robot_smach_states.human_interaction.human_interaction.Say object at 0x332ca10>': Traceback (most recent call last):\r\n  File \"/opt/ros/hydro/lib/python2.7/dist-packages/smach/state_machine.py\", line 241, in _update_once\r\n    self._remappings[self._current_label]))\r\n  File \"/home/amigo/ros/hydro/system/src/robot_smach_states/src/robot_smach_states/state.py\", line 20, in execute\r\n    return self.run( **resolved_arguments )\r\n  File \"/home/amigo/ros/hydro/system/src/robot_smach_states/src/robot_smach_states/human_interaction/human_interaction.py\", line 64, in run\r\n    robot.speech.speak(sentence, language, personality, voice, mood, block)\r\n  File \"/home/amigo/ros/hydro/system/src/robot_skills/src/robot_skills/speech.py\", line 44, in speak\r\n    resp1 = self._speech_service(language, personality, voice, mood, sentence, block)\r\n  File \"/opt/ros/hydro/lib/python2.7/dist-packages/rospy/impl/tcpros_service.py\", line 435, in __call__\r\n    return self.call(*args, **kwds)\r\n  File \"/opt/ros/hydro/lib/python2.7/dist-packages/rospy/impl/tcpros_service.py\", line 523, in call\r\n    raise rospy.exceptions.ROSInterruptException(\"node shutdown interrupted service call\")\r\nROSInterruptException: node shutdown interrupted service call\r\n\r\n[ERROR] [WallTime: 1428484576.640047] Could not execute Iterator state 'SINGLE_ITEM'\r\n[ERROR] [WallTime: 1428484576.640478] State 'RANGE_ITERATOR' failed to execute.\r\n[ERROR] [WallTime: 1428484576.641014] Robot exited with smach.exceptions.InvalidUserCodeError,<smach.exceptions.InvalidUserCodeError instance at 0x33032d8>,<traceback object at 0x33b1878>\r\n[INFO] [WallTime: 1428484576.641534] Torso cancelling all goals on close\r\n[INFO] [WallTime: 1428484576.642039] left arm cancelling all goals on all arm-related ACs on close\r\n[INFO] [WallTime: 1428484576.642519] right arm cancelling all goals on all arm-related ACs on close\r\nTraceback (most recent call last):\r\n  File \"/home/amigo/ros/hydro/system/src/challenge_manipulation/src/manipulation.py\", line 382, in <module>\r\n    startup(setup_statemachine, robot_name=robot_name)\r\n  File \"/home/amigo/ros/hydro/system/src/robot_smach_states/src/robot_smach_states/util/startup.py\", line 69, in startup\r\n    outcome = executioner.execute()\r\n  File \"/opt/ros/hydro/lib/python2.7/dist-packages/smach/state_machine.py\", line 347, in execute\r\n    container_outcome = self._update_once()\r\n  File \"/opt/ros/hydro/lib/python2.7/dist-packages/smach/state_machine.py\", line 244, in _update_once\r\n    raise ex\r\nsmach.exceptions.InvalidUserCodeError: <smach.exceptions.InvalidUserCodeError instance at 0x33032d8>\r\n[~]\r\namigo@amigo3 $ \r\n"}}