diydrones / apm_log_file_analyzer Goto Github PK

I need to fully review this code and test v3.1, v3.1.5, v3.2 and v3.2.1 scenarios as it seems to fail each time a new version is released.

It should not be so difficult :(

Maybe change 3.1 to v3.1.0 to make 310 LOL rather than the very complex frankin code I have now !!

Kev

When changing modes review the distance between the two GPS points.

It would have been helpful on a analysis.

18/10/2014 17:19:23 - 009501: Mode Changed to RTL
18/10/2014 17:19:23 - 009501: Mode Initialised at 35.9100269 -96.0396466 Alt: 10.11 Spd:5.29
Alt(m ~ ft) Spd(m/s ~ mph) Dist(km ~ mi) Launch(m ~ ft) GPS-Sats GPS-Hdop Eff(mA/min)
Max 17 ~ 55 5 ~ 11 0.10 ~ 0.06 79.30 ~ 260.17 8 2.42 N/A
Avg 11 ~ 36 1 ~ 2 N/A ~ N/A N/A ~ N/A 7 1.85 333.13
Min -1 ~ -4 0 ~ 0 N/A ~ N/A 1.96 ~ 6.43 7 1.82 N/A
RTL Flight Time (Session)= 67 seconds, 1:07
RTL Flight Time (Total)= 137 seconds, 2:17
WARNING: Less than 9 Satellites was detected during this mode.

18/10/2014 17:20:31 - 012008: Mode Changed to STABILIZE
18/10/2014 17:20:31 - 012008: Mode Initialised at 35.9097005 -96.0402872 Alt: 0.11 Spd:0.01
18/10/2014 17:20:32 - 012035: Landed

From this line, only available for Pix

MSG, PX4v2 00260019 3233470A 35343439

While code has already been written to detect some issues we need to add further code to detect when the GPS date (or dates in the newer v3.2 data) that go backwards (i.e. data from a previous log).

This is very important as it creates serious issues and is a very popular issue, in fact it happens on almost all logs that have started to overwrite a previous log

Tested using hardware:- My OctaQuad running v3.2 RC14 on an APM v2.5.2, 3rd flight of 12 mins will start overwriting the 1st flight log when collecting default data.

Kev

WARNING: Curruption Of Parameter Lines Detected!
WARNING: the Analyzer tried to handle them.
WARNING: This is a v3.2 firmware issue that has been reported!

Just report as read errors near the Progress Bar!

scoopdreams on RCGroups did some amazing analysis for one pilot who had used one of the pre-set firmware parameter settings.

He found that THR_MAX has been set to 80, when normally this is much higher like 800-1000

The result was the Quad would not take off.

Research values allowed from THR_MIN and THR_MAX and report if out of specification with a link to this post of RCGroups.
http://www.rcgroups.com/forums/showpost.php?p=31375573&postcount=4406

Kev

When loading and then analyzing a 2nd / 3rd log the graphs / charts still contain data from the 1st log.

Solution:
Clear down the data in all charts when pressing the analyse button.

Kev

General Issues:
Hardware: Unknown
HW Free RAM: Not Available
INS_PRODUCT_ID = 0
Warning: Unknown Ardupilot Hardware Detected.

RED Errors are very difficult to see at the field in day light.

When setting up the x8 I found having to be >2m was still a pain, on first testing one usually wants to remain very low.

Remove the need to be high, vibration chart is always available now when there is data anyway.

Look at other limitations, do they need to be in there still?

Kev

When looking back at old logs it would be ideal to be able to see the parameters in the file.

Solution: Open a new window and put the parameters in there so the user can have them open and read the analysis at the same time.

Kev

Need to test what is normal here and has no unacceptable adverse effects on flight performance.

Many flights so there is no need to worry in ALT HOLD mode, performance loss in not detectable at all.

Need to test AUTO missions next, can the X8 still complete these and at what level before the APM Speed Errors are detected visually?

Ultimate goal is to Increase the allowed amount of errors so they are only displayed once the user should be concerned.

28/09/2014 07:21:32 - 001385: Mode Changed to ALT_HOLD
28/09/2014 07:21:32 - 001385: Mode Initialised at 53.3874259 -1.2837206 Alt: 4.07 Spd:0.29
28/09/2014 07:21:32 - 001386: SET_SIMPLE_OFF
28/09/2014 07:21:32 - 001400: Simple Mode is Disabled
28/09/2014 07:22:43 - 003319: APM Speed Error: The total number of sustained loops 1002
28/09/2014 07:22:43 - 003319: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:22:43 - 003319: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:24:33 - 006295: APM Speed Error: The total number of sustained loops 1002
28/09/2014 07:24:33 - 006295: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:24:33 - 006295: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:26:13 - 008998: APM Speed Error: The total number of sustained loops 1002
28/09/2014 07:26:13 - 008998: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:26:13 - 008998: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:27:13 - 010621: APM Speed Error: The total number of sustained loops 1002
28/09/2014 07:27:13 - 010621: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:27:13 - 010621: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:27:23 - 010892: APM Speed Error: The number of long running main loops is 2 @ 12.064ms
28/09/2014 07:27:23 - 010892: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:27:23 - 010892: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:28:23 - 012514: APM Speed Error: The number of long running main loops is 2 @ 11.471ms
28/09/2014 07:28:23 - 012514: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:28:23 - 012514: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
28/09/2014 07:28:33 - 012785: APM Speed Error: The total number of sustained loops 1002
28/09/2014 07:28:33 - 012785: APM Speed Error: A one off here could be ignored but if repeated in this log,
28/09/2014 07:28:33 - 012785: APM Speed Error: then try disabling some logs, for example INAV, MOTORS and IMU.
Alt(m ~ ft) Spd(m/s ~ mph) Dist(km ~ mi) Launch(m ~ ft) GPS-Sats GPS-Hdop Eff(mA/min)
Max 17 ~ 55 8 ~ 17 1.98 ~ 1.23 401.56 ~ 1317.46 7 2.34 N/A
Avg 10 ~ 32 4 ~ 8 N/A ~ N/A N/A ~ N/A 6 2.16 721.54
Min -2 ~ -7 0 ~ 0 N/A ~ N/A 0.21 ~ 0.70 6 1.79 N/A
ALT_HOLD Flight Time (Session)= 468 seconds, 7:48
ALT_HOLD Flight Time (Total)= 468 seconds, 7:48
WARNING: Less than 9 Satellites was detected during this mode.

Kev

v3.1 & v3.2 (7 data)
FMT, 131, 31, IMU, Iffffff, TimeMS,GyrX,GyrY,GyrZ,AccX,AccY,AccZ

v3.3-rc1 (10 data) - Assume Temp is staying for now.
FMT, 131, 43, IMU, IffffffIIf, TimeMS,GyrX,GyrY,GyrZ,AccX,AccY,AccZ,ErrG,ErrA,Temp

This is the first time IMU has changed so the Version Fix will need to be added for the data population.

IUM2, IMU3, IMU4 should be completed when we look at processing all the extra data the PixHawk gives us.

Lower the GCS heartbeat from an Error to a Warning as it is not a critical event when >40%, this will make it appear Orange instead of Red.

GCS Fail Safe Activated.
Warning <100% and >=40% - Orange
Error <40% - Red

GCS Fail Safe Deactivated.
Warning <100%

Detail the GCS Fail Safe setting in the Analysis when any GCS updates are displayed.

Kev

Can we use the parameter setting BATT_CURR_PIN or BATT_VOLT_PIN etc, to determine if the user is trying to monitor current and voltage.

We could use this at the bottom in the summary in stead of the quirky statement "if you a trying to monitor"

Also, if we have no data and the settings are set to monitor then something must be incorrect.

http://code.google.com/p/ardupilot-mega/wiki/Voltage
Note: To disable current or voltage monitoring, you can set the parameters BATT_CURR_PIN or BATT_VOLT_PIN to -1 in the Advanced Parameters List.

Kev

Create an Options form, with settings saved in the .ini file.

Allow user to decide their default preferences (left options / which are ticked etc.)

Allow user to decide the default folder for logs etc.

What is the time zone of the GPS signal?

Is my calculation incorrect resulting in GMT-1 or is this correct to the GPS signal?

Do we need to update my calculation to local settings?

Kev

No progress has been made with this and developers do not seem concerned.

Comment out this warning, but leave the USB connected in the analysis.

In some logs we see this changing value during flights, each time I have seen this it has been in RTL mode, I think as I abort the RTL by mode change.

Log FileName: C:\Program Files (x86)\Mission Planner\logs\2014-09-13 12-54-51.log

Kev

We need to be able to load and convert .bin files

With the release on v3.3RC1 the name of ArduCopter has been change to APM:Copter

There is a fatal error here in "ALL" the version codes.

If the If ReadFileResilienceCheck(6) = True Then fails there is no else :( and the main code would be called anyway without resetting the variables.

Work on issue 123 first

When Auto Mode is Selected the logs can be out of sync, for example command 1 can be written before the Mode is activated.

Learn this and display the first command after the mode is activated.

This will mean they data lines are slightly out of sync but will make for better reading and understand what is happening.

APM Log File Analiser v2.1.0.3

Log FileName: Z:\APM Log Analyser Test Logs\Pix V3.2.1 - Auto Mission Testing.log
Ardu Version: V3.2.1 Build: (36b405fb)
Ardu Type: APM:Copter
Hardware: Unknown
HW Free RAM: Not Available
HW Version: PX4: ce602658 NuttX: 475b8c15
Frame Type: X
No. Motors: 8

'-------------------------------------------------------------------

19/04/2015 14:48:26 - 077839: Mode Changed to Stabilize
19/04/2015 14:48:26 - 077839: Mode Initialised at 53.4312187 -1.2983786 Alt: 0.25 Spd:0.08

19/04/2015 14:48:29 - 078479: Auto Command: 1 of 8
19/04/2015 14:48:29 - 078479: Auto Command: Takeoff from ground / hand
19/04/2015 14:48:29 - 078479: Auto Command: Climb to Alt of 15 m
Limited Data Available - Mode Ignored

19/04/2015 14:48:29 - 078480: Mode Changed to Auto
19/04/2015 14:48:29 - 078480: Mode Initialised at 53.4312198 -1.2983804 Alt: 0.01 Spd:0.04
19/04/2015 14:48:29 - 078481: SET_SIMPLE_OFF
19/04/2015 14:48:29 - 078597: Simple Mode is Disabled
19/04/2015 14:48:29 - 078615: Take Off
19/04/2015 14:48:30 - 078828: Auto Mode is waiting for Throttle.
19/04/2015 14:48:37 - 080276: Auto Command: Hit WP1 Radius : 53.4312163 -01.2983918 at an Altitude of 12.94m - 5942209.487m to center.
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Distance was : 0 m
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Speed was : 0 m/s
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Used Capacity was : 1002.608 mAh
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Efficiency was : Infinity mAh/m (mAh per Meter)
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Efficiency Result : 0 m/A (Meters per Amp)

19/04/2015 14:48:37 - 080276: Auto Command: 2 of 8
19/04/2015 14:48:37 - 080276: Auto Command: Navigate to New Way Point
19/04/2015 14:48:37 - 080276: Auto Command: Navigate From WP1: 00.0000000 00.0000000 with current Altitude of 0m
19/04/2015 14:48:37 - 080276: Auto Command: to WP2: 53.4313900 -01.2983230 with current Altitude of 15m
19/04/2015 14:48:37 - 080276: Auto Command: WP - WP Distance: 5942228.66m
19/04/2015 14:48:37 - 080276: Auto Command: Warning: Navigating to a new GPS position from a low altitude can be dangerous!
19/04/2015 14:48:37 - 080276: Auto Command: Warning: Insert a Take Off command to a good altitude at the start of the mission.
19/04/2015 14:48:43 - 081720: Auto Command: Hit WP2 Radius : 53.4312786 -01.2983456 at an Altitude of 14.83m - 12.477m to center.
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Distance was : 0 m
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Time was : 6 seconds
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Speed was : 0 m/s
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Used Capacity was : 59.67902 mAh
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Efficiency was : Infinity mAh/m (mAh per Meter)
19/04/2015 14:48:43 - 081720: Auto Command: WP - WP Efficiency Result : 0 m/A (Meters per Amp)

Kev

A model must have the same Pixhawk Serial Number and the same Firmware Version Number.
Not Available for APM models.
Detect new model analysed and ask if settings should be saved (allow to disable this in the options window because it could become annoying for devs).
Allow Parameter Comparison (manually for user viewing) and automated during analysis.
Allow users to compare parameters across different known models or across firmware changes.

Need to write some code to cover the change in parameters for CURR

v3.2 - FMT, 9, 23, CURR, IhIhhhf, TimeMS,ThrOut,ThrInt,Volt,Curr,Vcc,CurrTot
v3.3-rc1 FMT, 166, 21, CURR, IhhhHfh, TimeMS,Throttle,Volt,Curr,Vcc,CurrTot,Volt2

Check and advise if RTL efficiency is worse (higher mA used) than other modes.

Consider that the "Landing" will distort the "flight" mA.

We need to calculate the best speed to travel to gain maximum distance using the least mA, thus giving the maximum chance to RTL during a battery fail safe error.

Kev

Allow greater values for PX4.

Research generally what is OK before implementation.

http://copter.ardupilot.com/wiki/initial-setup/configuring-hardware/

v3.2 - FMT, 6, 17, PM, HHIhBHB, NLon,NLoop,MaxT,PMT,I2CErr,INSErr,INAVErr
v3.3 - FMT, 6, 16, PM, HHIhBH, NLon,NLoop,MaxT,PMT,I2CErr,INSErr

APM Log File Analiser v2.1.0.3

Log FileName: Z:\APM Log Analyser - Open Investigations\Mode Description Blank.log
Ardu Version: V3.2.1 Build: (36b405fb)
Ardu Type: APM:Copter
Hardware: Unknown
HW Free RAM: Not Available
HW Version: PX4: ce602658 NuttX: 475b8c15
Frame Type: X
No. Motors: 8

When I auto tuned the Pix for the first time then as I activated AutoTune the log reported a Mode Change that was not detailed:

MODE, , 451 <- No Mode Description between the commas
EV, 30

19/04/2015 13:13:44 - 027601: Mode Changed to 451
19/04/2015 13:13:44 - 027601: Mode Initialised at 53.4311846 -1.2983684 Alt: 2.84 Spd:0.69
19/04/2015 13:13:44 - 027602: AUTOTUNE_INITIALISED

and then again when AutoTune was restarted:

MODE, , 490
EV, 32

19/04/2015 13:14:37 - 041538: Mode Changed to 490
19/04/2015 13:14:37 - 041538: Mode Initialised at 53.431037 -1.2981766 Alt: 8.2 Spd:3.41
19/04/2015 13:14:37 - 041539: AUTOTUNE_RESTART
19/04/2015 13:14:38 - 041622: Rx Information: CH7 Switch is High.
19/04/2015 13:14:38 - 041622: Rx Information: CH7 function: Enable / Disable Auto Tune
19/04/2015 13:19:34 - 124793: AUTOTUNE_REACHED_LIMIT
19/04/2015 13:21:28 - 159666: AUTOTUNE_SUCCESS
19/04/2015 13:21:43 - 163077: AUTOTUNE_OFF
'---------------------------------
19/04/2015 13:22:01 - 166989: AUTOTUNE_SAVEDGAINS
19/04/2015 13:22:01 - 166990: DisArmed
19/04/2015 13:22:06 - 168023: AUTOTUNE_OFF
19/04/2015 13:22:06 - 168089: Rx Information: CH7 Switch is Low.
19/04/2015 13:22:06 - 168089: Rx Information: CH7 function: Enable / Disable Auto Tune

Was this just a glitch or is this what happens in v3.3

Issue Opened: Mode Description Blank on AutoTune

OSD Max label is on the wrong Charting form, move to Power Rails form.

Kev

Reporting this information at the top of the log will save checking parameters in the list.

I.e. Compass Calibrated, Voltage Calibrated, or ....

Needs to validate a motor is a motors, i.e. follows similar outputs as motor 1.

TimeMS is now in the FMT line

Basically we used an Windows 7 control to create a progress bar on the task bar.

Look at wrapping some code around this function to stop the minimize and the taskbar stuff!

Kev

This is annoying and not required for Pix.

In fact, produce a global variable for APM / Pix so I can start to process messaged based on what FC is being used. For software, current default to APM.

This ones just ror the questor lol

Since we moved away from TheQuestor's FTP server it leaves me in a position that the FTP account could be closed and users of the application could no longer connect to gain access to updates.

Create a new account with another independent company (no connection to x10hosting) to ensure continuity of Service.

At the same time update and cleanse the UpdaterProgram.exe code to use the Mirror and read / install all files in the Update folder rather than the current method of "hard coded" filenames.

Also, ensure that the updater clears down all the new files like the APC packs ect.

Just add a new MSG line detailing which version of my program create the .Log file

Did i dream it or do sometimes the lines in the log files seem to be very slightly out of sync in terms of milliseconds.

It makes sense, as a loop finishes it writes the data, only one can write at a time.

Do some analysis on logs, if true design a small read buffer (max 10 lines), sort before processing the oldest one.

This may also sort issue 104 - Auto missions, so this should be completed first.

New RADIOERROR Ecode.log

I believe I was testing the switching off of the Radio.

12/04/2015 16:29:14 - 015307: RADIO ERROR: New Error Code (ECode Unknown to APM Log Analyser

12/04/2015 16:31:58 - 025989: RADIO ERROR: New Error Code (ECode Unknown to APM Log Analyser

Pull the latest from the ArduPilot master to see what the possibilities are.

Place Link to this data in my code so next time I dont have to find the correct file :(

Need to store the last place we pock a file up from.

As a quick fix, store this in the. .ini file and update when changed?

As Description.

Use TimeMS from more datalines to capture the truncation issues quicker.

Stabilize Flight Time (Session)= 19 seconds, 0:19
Stabilize Flight Time (Total)= 665 seconds, 11:05
WARNING: Less than 9 Satellites was detected during this mode.

09/04/2015 14:53:19 - 027022: LOG Information: Vehicle is flying without TAKE_OFF Event recorded in the APM Log,
09/04/2015 14:53:19 - 027022: ----- Testing: Log_In_Flight = False, Alt = 2.36, Throttle = 50.3%
09/04/2015 14:53:19 - 027022: LOG Information: The Log Analiser program will simulate a TAKE_OFF Event from this point,
09/04/2015 14:53:19 - 027022: LOG Information: The effect on the results can not be determined but should be minimal.
09/04/2015 14:53:19 - 027022: Take Off
WARNING: DataLog File Truncation Issue Found
WARNING: This is an issue within the ArduCopter Firmware, APM Log Analyser has handled the issue.

Actually, we are not in flight, this is part of the old log that has been processed before we detected it was truncated.

Test Log:
APM Log File Analiser v2.1.0.3

Log FileName: Z:\APM Log Analyser Test Logs\APM V3.2-rc14 - Truncation Issue.log
Ardu Version: V3.2-rc14 Build: (3a292db7)
Ardu Type: APM:Copter
Hardware: APM2
HW Free RAM: Not Available
HW Version:
Frame Type: X
No. Motors: 0

Need to run a log and manually tilt to Left, then Right, then Forward then Backward to capture which way the graph goes.

Can we capture Yaw direction also?

Validate the results at the bottom of the analysis window to be sure

Suggestion:-

jdennings - I am thinking things like FS_BATT_ENABLE, (land vs RTL when enabled), FS_GPS_Enable, (land by default vs althold or "land even from stabilize"), FS_THR_ENABLE, FS_GCS_ENABLE, these sort of parameters.

Kev - I've not done anything with these yet, although I think this is a good idea. Perhaps with a button on the left so you can turn FS analysis off if not required.

http://www.rcgroups.com/forums/showpost.php?p=31388693&postcount=4440