Streamlined scheduler statistics?

ArduCopter Copter 3.6
, ,
1

Is there a simple way to extract statistics on which tasks in the scheduler run overtime, by how much and how often they do? Something like the console command “nsh>perf” described here by @peterbarker ? I’m using a pixracer with ChibiOS so no nsh console if I understand correctly.

Instead I’ve built a small python script to automate some of the process. It works with SCHED_DEBUG=3 but it’s got the following drawbacks:

  • doesn’t measure which percentage of each task runs overtime. It captures only the ones that run overtime
  • necessitates too many steps: 1)run mavproxy connected to drone USB 2)pipe the output to a file and 3)process it with the python script

Question #2: does anybody know why some functionalities that should be disabled seem to be run by the scheduler and take up time (beacon, visual odometry, precision landing…) see comments in the right hand column below:

task name average overrun # of occurences allowed time
10-update 328 462 50 //AP_Proximity
11-update 252 920 50 //AP_Beacon: but BCN_TYPE is not enabled
12-update 268 987 50 //AP_VisualOdom: but VISO_TYPE is not enabled
21-update_precland 289 1225 50 //but PLND_ENABLED is not enabled
22-fourhundred_hz_logging 331 1322 50 //lots of those (fast IMU logging enabled)
29-update_receive 424 1604 180 //lots of those: receives packets from GCS with GCS_MAVLINK::update_receive()
3-update 304 236 160 //OpticalFlow: but FLOW_ENABLE=0
31-update_send 1127 747 550 //long overruns: GCS_MAVLINK::update_send()
23-update 344 167 90
36-periodic_tasks 478 875 300 //lots of those: AP_Logger_Backend::periodic_tasks()
37-periodic 502 1487 50 //lots of those: AP_InertialSensor: logs on SD card
40-compass_cal_update 306 651 100 //compass calibration runs continuously?
9-read_rangefinder 181 407 100 //lots of those: change maxTime?
15-update_throttle_hover 276 96 90
33-update_trigger 294 97 75
35-twentyfive_hz_logging 331 56 110
2-update_GPS 535 217 200 //13% overrun over 30s test: change maxTime?
19-update_events 270 68 75
20-accumulate 305 76 90
25-ekf_check 315 55 75
28-lost_vehicle_check 282 20 50
32-update 337 104 75
44-terrain_update 240 124 100
14-run_nav_updates 261 47 100
45-update 333 75 75
43-avoidance_adsb_update 291 54 100
4-update_batt_compass 309 52 120
5-read_aux_all 327 59 50
6-arm_motors_check 303 63 50
24-one_hz_loop 204 20 100
47-update 383 4 100
0-rc_loop 151 24 130
39-rpm_update 319 43 200
7-auto_disarm_check 100 5 50
8-auto_trim 211 8 75
1-throttle_loop 138 37 75
34-ten_hz_logging_loop 413 6 350
26-gpsglitch_check 313 40 50
46-update 335 27 100
41-accel_cal_update 328 36 100
42-update 336 44 100
16-save_position 276 12 100
17-update 313 12 90
27-landinggear_update 336 12 75
38-update_logging 431 3 75
18-three_hz_loop 229 10 75
13-update_altitude 200 17 100
30-gcs_send_heartbeat 276 3 110

In case it’s useful to somebody else, here is the python script:

import re

#object to summarize each task result
class Task:
    def __init__(self,name,time,maxTime):
        self.name =name
        self.totalT=time
        self.occurences=1
        self.maxTime=maxTime
        self.averageTime=0

datafile = open("/home/clem/scheduler_output.txt",'r')
lines = datafile.readlines()

task_list = []
for line in lines:
    #some lines are garbled, just remove them
    scheduler_duplicate =re.findall("Scheduler",line)
    overrun_duplicate = re.findall("overrun",line)
    if len(scheduler_duplicate)==2 or len(overrun_duplicate)==2:
        print "garbled line found: ", line.strip()
        continue
    #regex each element
    name = re.findall("Scheduler overrun task\[(.*?)\]", line)
    if name:
        time = re.findall('\] \((.*?)\/',line)
        allowed_time = re.findall("\/(.*?)\)",line)
        #print name, " ", time, " ", allowed_time
        #check if the task has already been seen
        task_exists = False
        for task in task_list:
            #update task if found
            if task.name == name[0]:
                task_exists = True
                task.totalT += int(time[0])
                task.occurences +=1
        if not task_exists:
            #add task to the list
            task_list.append(Task(name[0],int(time[0]),allowed_time[0]))

#display final results
print "\nSummary results:"
print "{0:30}\t{1:^20}\t{2:^10}\t{3:^20}".format("task name","average overrun","# of occurences","allowed time")
for task in task_list:
    task.averageTime = task.totalT/task.occurences
    print "{0:30}\t{1:^20}\t{2:^10}\t{3:^20}".format(task.name,task.averageTime,task.occurences,task.maxTime)
2 Likes