search

invernyx / smartcars-3-bugs

The bug tracker for the smartCARS 3 application
3 stars 0 forks source link

[BUG] - Flight Time is being reported incorrectly. #140

Closed walkerairtrans closed 1 year ago

walkerairtrans commented 1 year ago

Describe the bug

The following flight was 1 hour and 9 minutes from pushback to engine off; or 59 minutes if we're using take-off to landing (which makes more sense).

If you need more examples let me know -- we have about 15 of them now.

Also, this appears to have been going on in the alpha but I did not catch it. I went back and started reviewing my past flights and noticed that as time started extending it got more inaccurate. I had a 7-1/2 hour test flight awhile back and that only registered 7 hours -- shame on me for not catching it in the alpha!

It was sent to the server at flightTime: 0.5.

This is a debug capture of the physical POST packet from your app hitting my server. {"bidID":"258480","remainingLoad":"212209.13","fuelUsed":"135259","landingRate":"-146.868853125","flightLog":["2023-04-22T07:26:21.701Z - Flying Boeing 777F WAT","2023-04-22T07:26:21.701Z - Now boarding","2023-04-22T07:26:22.705Z - Flaps set to 0%","2023-04-22T07:26:22.705Z - Fuel increased to 160427","2023-04-22T07:26:57.984Z - Fuel increased to 37479","2023-04-22T07:29:12.205Z - Pushing back with 37429 of fuel","2023-04-22T07:29:28.340Z - Engine 2 On","2023-04-22T07:29:29.349Z - Engine 1 On","2023-04-22T07:30:53.107Z - Flaps set to 17%","2023-04-22T07:36:17.583Z - Taxiing out","2023-04-22T07:38:36.066Z - Taking off","2023-04-22T07:38:53.232Z - Climbing at 171 kts, 7 degrees pitch, 0 degrees bank","2023-04-22T07:38:54.240Z - Cruising at 0 ft","2023-04-22T07:38:56.270Z - Gear lever raised","2023-04-22T07:39:03.330Z - Climbing at 198 kts, 19 degrees pitch, -1 degrees bank","2023-04-22T07:39:26.553Z - Pitch exceeded 10 degrees nose down","2023-04-22T07:40:10.953Z - Flaps set to 0%","2023-04-22T07:55:40.990Z - Cruising at 32400 ft","2023-04-22T08:17:15.097Z - Descending with 53 nm to go","2023-04-22T08:29:55.457Z - Approach started at 7971 ft AGL with 22 nm to go","2023-04-22T08:33:01.998Z - Flaps set to 3%","2023-04-22T08:33:49.485Z - Flaps set to 17%","2023-04-22T08:33:56.529Z - On final at 2954 ft with 10 nm to go at 206 kts, -2 degrees pitch, -1 degrees bank","2023-04-22T08:33:59.554Z - Gear lever lowered","2023-04-22T08:35:03.109Z - Flaps set to 50%","2023-04-22T08:35:35.423Z - Flaps set to 83%","2023-04-22T08:37:17.350Z - Touched down at -147 fpm, 1.2g, 145 kts, true heading 078, 2 degrees pitch, 2 degrees bank, wind 030 at 23 kts, fuel: 25276","2023-04-22T08:37:47.649Z - Taxiing to gate, landed in 3491 ft","2023-04-22T08:38:23.910Z - Comment: 1h12m as per SC3","2023-04-22T08:38:43.170Z - Engine 1 Off","2023-04-22T08:38:43.170Z - Engine 2 Off","2023-04-22T08:38:44.179Z - Deboarding"],"flightData":[{"eventId":"WlgahOxj1nYC8Z4l","eventElapsedTime":"0.0005591666666666666","eventTimestamp":"2023-04-22T07:26:21.701Z","eventCondition":"{aircraftType} changed or {aircraftType} not_equals {str:0}","message":"Flying Boeing 777F WAT"},{"eventId":"qkp7RkCQKNOtASSf","eventElapsedTime":"0.0005591666666666666","eventTimestamp":"2023-04-22T07:26:21.701Z","eventCondition":"{phase} equals {str:0}","message":"Now boarding"},{"eventId":"wSri0dd8WsAiE0ws","eventElapsedTime":"0.0008380555555555554","eventTimestamp":"2023-04-22T07:26:22.705Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 0%"},{"eventId":"VcAkXkAhdOGImctD","eventElapsedTime":"0.0008380555555555554","eventTimestamp":"2023-04-22T07:26:22.705Z","eventCondition":"{fuelTotalQuantityWeight} increased","message":"Fuel increased to 160427"},{"eventId":"QhSkzVAFSoinpf88","eventElapsedTime":"0.010637777777777782","eventTimestamp":"2023-04-22T07:26:57.984Z","eventCondition":"{fuelTotalQuantityWeight} increased","message":"Fuel increased to 37479"},{"eventId":"DQNgR0i1MahACpXa","eventElapsedTime":"0.04792138888888887","eventTimestamp":"2023-04-22T07:29:12.205Z","eventCondition":"{phase} equals {str:0}","message":"Pushing back with 37429 of fuel"},{"eventId":"jAsWAcOCfjPQXtVs","eventElapsedTime":"0.05240305555555555","eventTimestamp":"2023-04-22T07:29:28.340Z","eventCondition":"{engine2Firing} not_equals false","message":"Engine 2 On"},{"eventId":"vk1ggft96ExK1YbR","eventElapsedTime":"0.05268361111111111","eventTimestamp":"2023-04-22T07:29:29.349Z","eventCondition":"{engine1Firing} not_equals false","message":"Engine 1 On"},{"eventId":"wOrSrfVz2QtLvX7C","eventElapsedTime":"0.07594972222222236","eventTimestamp":"2023-04-22T07:30:53.107Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 17%"},{"eventId":"ZdpOLbDeRj0X5RAE","eventElapsedTime":"0.16608194444444543","eventTimestamp":"2023-04-22T07:36:17.583Z","eventCondition":"{phase} equals {str:0}","message":"Taxiing out"},{"eventId":"c7fGfYpbrRqHObil","eventElapsedTime":"0.20454944444444584","eventTimestamp":"2023-04-22T07:38:36.066Z","eventCondition":"{phase} equals {str:0}","message":"Taking off"},{"eventId":"69VJVFTNIu3mHrry","eventElapsedTime":"0.20931750000000146","eventTimestamp":"2023-04-22T07:38:53.232Z","eventCondition":"{phase} equals {str:0}","message":"Climbing at 171 kts, 7 degrees pitch, 0 degrees bank"},{"eventId":"lKtys2KOWr8zuRTM","eventElapsedTime":"0.20959777777777924","eventTimestamp":"2023-04-22T07:38:54.240Z","eventCondition":"{phase} equals {str:0}","message":"Cruising at 0 ft"},{"eventId":"r5fs9O8JXfeuWwxw","eventElapsedTime":"0.21016166666666813","eventTimestamp":"2023-04-22T07:38:56.270Z","eventCondition":"{gearControl} equals 0","message":"Gear lever raised"},{"eventId":"atRl6R1vCMAO6nNr","eventElapsedTime":"0.2121222222222237","eventTimestamp":"2023-04-22T07:39:03.330Z","eventCondition":"{phase} equals {str:0}","message":"Climbing at 198 kts, 19 degrees pitch, -1 degrees bank"},{"eventId":"vVFH6Zyx7LJuMAPP","eventElapsedTime":"0.21857361111111268","eventTimestamp":"2023-04-22T07:39:26.553Z","eventCondition":"{pitch} less_than -10","message":"Pitch exceeded 10 degrees nose down"},{"eventId":"mytHvSTSnenoX7Qf","eventElapsedTime":"0.23090666666666837","eventTimestamp":"2023-04-22T07:40:10.953Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 0%"},{"eventId":"KWSO8AJlUMyTbx1Z","eventElapsedTime":"0.48925055555555436","eventTimestamp":"2023-04-22T07:55:40.990Z","eventCondition":"{phase} equals {str:0}","message":"Cruising at 32400 ft"},{"eventId":"4zhstAwF9F8WICHu","eventElapsedTime":"0.8487247222222076","eventTimestamp":"2023-04-22T08:17:15.097Z","eventCondition":"{phase} equals {str:0}","message":"Descending with 53 nm to go"},{"eventId":"lh2sdSvfLghDuTs5","eventElapsedTime":"1.0599358333333002","eventTimestamp":"2023-04-22T08:29:55.457Z","eventCondition":"{phase} equals {str:0}","message":"Approach started at 7971 ft AGL with 22 nm to go"},{"eventId":"2sWMss9gS13L15H3","eventElapsedTime":"1.1117527777777354","eventTimestamp":"2023-04-22T08:33:01.998Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 3%"},{"eventId":"QqDcYRlawDRceCMa","eventElapsedTime":"1.1249433333332879","eventTimestamp":"2023-04-22T08:33:49.485Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 17%"},{"eventId":"8cumYWiDtURHNGq9","eventElapsedTime":"1.1269002777777317","eventTimestamp":"2023-04-22T08:33:56.529Z","eventCondition":"{phase} equals {str:0}","message":"On final at 2954 ft with 10 nm to go at 206 kts, -2 degrees pitch, -1 degrees bank"},{"eventId":"rSUHNzN8Lx8U9Dcd","eventElapsedTime":"1.1277405555555093","eventTimestamp":"2023-04-22T08:33:59.554Z","eventCondition":"{gearControl} not_equals 0","message":"Gear lever lowered"},{"eventId":"vtLtzXKivGL8UtEm","eventElapsedTime":"1.1453947222221728","eventTimestamp":"2023-04-22T08:35:03.109Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 50%"},{"eventId":"KpNJ8eVsD2E3xmeP","eventElapsedTime":"1.1543708333332812","eventTimestamp":"2023-04-22T08:35:35.423Z","eventCondition":"{flapsLeftPosition} changed","message":"Flaps set to 83%"},{"eventId":"Yc0wTg3yc3UxJKJ3","eventElapsedTime":"1.18268388888883","eventTimestamp":"2023-04-22T08:37:17.350Z","eventCondition":"{phase} equals {str:0}","message":"Touched down at -147 fpm, 1.2g, 145 kts, true heading 078, 2 degrees pitch, 2 degrees bank, wind 030 at 23 kts, fuel: 25276"},{"eventId":"XxqlawjIShIxdfSf","eventElapsedTime":"1.1911002777777173","eventTimestamp":"2023-04-22T08:37:47.649Z","eventCondition":"{phase} equals {str:0}","message":"Taxiing to gate, landed in 3491 ft"},{"eventId":"kp3RqTzswY2E8WN4","eventTimestamp":"2023-04-22T08:38:23.910Z","eventCondition":"changed","type":"comment","message":"1h12m as per SC3"},{"eventId":"QkbZjdRRr98ZFVfU","eventElapsedTime":"1.2065227777777134","eventTimestamp":"2023-04-22T08:38:43.170Z","eventCondition":"{engine1Firing} equals false","message":"Engine 1 Off"},{"eventId":"pTwo2Gi434S4Afur","eventElapsedTime":"1.2065227777777134","eventTimestamp":"2023-04-22T08:38:43.170Z","eventCondition":"{engine2Firing} equals false","message":"Engine 2 Off"},{"eventId":"7Ns6i0IglNKK1vRD","eventElapsedTime":"1.2068030555554912","eventTimestamp":"2023-04-22T08:38:44.179Z","eventCondition":"{phase} equals {str:0}","message":"Deboarding"}],"comments":"2023-04-22T08:38:23.910Z - Comment: 1h12m as per SC3","aircraft":"51","flightTime":"0.5","route":[""]}

How do you reproduce this bug?

Just run a long flight and you will see the time is wrong.

Expected behavior

Flight time should be properly computed from push back to engines off, or take-off to landing, depending on the logic.

Screenshots

image

Operating system

Windows 11

Community airline

Walker Air Treansport

smartCARS Version

Latest

Plugins installed

chat, map, flight center, flight tracker, logbook

Additional context

N/A

walkerairtrans commented 1 year ago

Additional information if this helps.

App showed 1h 14m -- this accounts for sitting around for awhile before pushing/taking off. image

Before I submitted the flight I checked the recorded elapsedFlightTime: 0.9713424999999728 which equals 58 minutes. smartcars3_ql7l6SCekY

When the PIREP was posted it came across with FlightTime: 1.1 = 1hr 6 mins.

{POST} from the app (what gets received from complete.php) {"bidID":"258702","remainingLoad":"1095.04","fuelUsed":"52","landingRate":"-33.8336625","flightLog":["2023-04-22T19:18:40.954Z - Flying Black Square A36 Bonanza Turbo WAT Black Red","2023-04-22T19:18:40.954Z - Now boarding","2023-04-22T19:19:41.502Z - Fuel increased to 307","2023-04-22T19:19:43.517Z - Fuel increased to 376","2023-04-22T19:23:18.376Z - Engine 1 On","2023-04-22T19:28:03.737Z - Pushing back with 375 of fuel","2023-04-22T19:28:18.846Z - Taxiing out","2023-04-22T19:28:29.943Z - Flaps set to 50%","2023-04-22T19:31:05.231Z - Taking off","2023-04-22T19:31:19.351Z - Climbing at 90 kts, -4 degrees pitch, 2 degrees bank","2023-04-22T19:31:24.412Z - Gear lever raised","2023-04-22T19:31:33.487Z - Flaps set to 0%","2023-04-22T19:39:27.506Z - Cruising at 9000 ft","2023-04-22T20:12:57.938Z - Descending with 26 nm to go","2023-04-22T20:13:07.019Z - Approach started at 8366 ft AGL with 26 nm to go","2023-04-22T20:20:00.916Z - On final at 3312 ft with 14 nm to go at 150 kts, -1 degrees pitch, -1 degrees bank","2023-04-22T20:23:47.817Z - Gear lever lowered","2023-04-22T20:23:55.879Z - Flaps set to 50%","2023-04-22T20:29:36.193Z - Touched down at -34 fpm, 0.9g, 66 kts, true heading 045, 5 degrees pitch, 0 degrees bank, wind 180 at 0 kts, fuel remaining 278","2023-04-22T20:29:41.234Z - Engine 1 Off","2023-04-22T20:29:42.241Z - Engine 1 On","2023-04-22T20:30:06.482Z - Taxiing to gate, landed in 2467 ft","2023-04-22T20:30:33.734Z - Flaps set to 0%","2023-04-22T20:31:06.982Z - Engine 1 Off","2023-04-22T20:31:07.989Z - Deboarding with a total flight time of {elapsedFlightTime}"],"flightData":[{"eventId":"BaeKHW1A7HgNowsn","eventElapsedTime":"0.0005558333333333333","eventTimestamp":"2023-04-22T19:18:40.954Z","eventCondition":"{aircraftType} changed or {aircraftType} not_equals {str:0}","message":"Flying Black Square A36 Bonanza Turbo WAT Black Red"},{"eventId":"OaVNx4ezJzwk60G6","eventElapsedTime":"0.0005558333333333333","eventTimestamp":"2023-04-22T19:18:40.954Z","eventCondition":"{phase} equals {str:0}","message":"Now boarding"},{"eventId":"zVM9Ru5WPq8CTMvj","eventElapsedTime":"0.017374722222222225","eventTimestamp":"2023-04-22T19:19:41.502Z","eventCondition":"{fuelTotalQuantityWeight} increased","message":"Fuel increased to 307"},{"eventId":"joXr8e5nW9HMly3w","eventElapsedTime":"0.017934444444444447","eventTimestamp":"2023-04-22T19:19:43.517Z","eventCondition":"{fuelTotalQuantityWeight} increased","message":"Fuel increased to 376"},{"eventId":"OLsAm2VeIhpWyz5n","eventElapsedTime":"0.07761749999999995","eventTimestamp":"2023-04-22T19:23:18.376Z","eventCondition":"{engine1Firing} not_equals false","message":"Engine 1 On"},{"eventId":"audr8evnh2zKG2H2","eventElapsedTime":"0.15688416666666674","eventTimestamp":"2023-04-22T19:28:03.737Z","eventCondition":"{phase} equals {str:0}","message":"Pushing back with 375 of fuel"},{"eventId":"u1B2v0HaDjg0PLXe","eventElapsedTime":"0.16108138888888898","eventTimestamp":"2023-04-22T19:28:18.846Z","eventCondition":"{phase} equals {str:0}","message":"Taxiing out"},{"eventId":"6vSMxpa7dY3MgR4E","eventElapsedTime":"0.164163888888889","eventTimestamp":"2023-04-22T19:28:29.943Z","eventCondition":"{flapsControl} changed","message":"Flaps set to 50%"},{"eventId":"uc0mJwLy97oLE6xt","eventElapsedTime":"0.20729944444444484","eventTimestamp":"2023-04-22T19:31:05.231Z","eventCondition":"{phase} equals {str:0}","message":"Taking off"},{"eventId":"ZM2JVsw9wns3es2g","eventElapsedTime":"0.21122166666666706","eventTimestamp":"2023-04-22T19:31:19.351Z","eventCondition":"{phase} equals {str:0}","message":"Climbing at 90 kts, -4 degrees pitch, 2 degrees bank"},{"eventId":"mtUr9L8meurTO46c","eventElapsedTime":"0.2126275000000004","eventTimestamp":"2023-04-22T19:31:24.412Z","eventCondition":"{gearControl} equals 0","message":"Gear lever raised"},{"eventId":"sI7B0XfIcYf9EAsx","eventElapsedTime":"0.21514833333333375","eventTimestamp":"2023-04-22T19:31:33.487Z","eventCondition":"{flapsControl} changed","message":"Flaps set to 0%"},{"eventId":"ih2wgE1fgonkXn5A","eventElapsedTime":"0.34682027777777835","eventTimestamp":"2023-04-22T19:39:27.506Z","eventCondition":"{phase} equals {str:0}","message":"Cruising at 9000 ft"},{"eventId":"v7YLrvz6JFf5ZERY","eventElapsedTime":"0.9052736111110885","eventTimestamp":"2023-04-22T20:12:57.938Z","eventCondition":"{phase} equals {str:0}","message":"Descending with 26 nm to go"},{"eventId":"SkGnLIohMmYhldJ3","eventElapsedTime":"0.9077958333333106","eventTimestamp":"2023-04-22T20:13:07.019Z","eventCondition":"{phase} equals {str:0}","message":"Approach started at 8366 ft AGL with 26 nm to go"},{"eventId":"NY8ADAqr2jB0zjhd","eventElapsedTime":"1.0227674999999705","eventTimestamp":"2023-04-22T20:20:00.916Z","eventCondition":"{phase} equals {str:0}","message":"On final at 3312 ft with 14 nm to go at 150 kts, -1 degrees pitch, -1 degrees bank"},{"eventId":"LAKlWppK0nWo0IH4","eventElapsedTime":"1.085795555555521","eventTimestamp":"2023-04-22T20:23:47.817Z","eventCondition":"{gearControl} not_equals 0","message":"Gear lever lowered"},{"eventId":"ipoHXAn2RMyyBWQL","eventElapsedTime":"1.0880349999999654","eventTimestamp":"2023-04-22T20:23:55.879Z","eventCondition":"{flapsControl} changed","message":"Flaps set to 50%"},{"eventId":"9pOIEdrOIxzxTo9P","eventElapsedTime":"1.1825666666666255","eventTimestamp":"2023-04-22T20:29:36.193Z","eventCondition":"{phase} equals {str:0}","message":"Touched down at -34 fpm, 0.9g, 66 kts, true heading 045, 5 degrees pitch, 0 degrees bank, wind 180 at 0 kts, fuel remaining 278"},{"eventId":"hkrMT7LKSVTJqJnF","eventElapsedTime":"1.1839669444444032","eventTimestamp":"2023-04-22T20:29:41.234Z","eventCondition":"{engine1Firing} equals false","message":"Engine 1 Off"},{"eventId":"rxpXKhsPJ0Naui9s","eventElapsedTime":"1.1842466666666254","eventTimestamp":"2023-04-22T20:29:42.241Z","eventCondition":"{engine1Firing} not_equals false","message":"Engine 1 On"},{"eventId":"JhgwlANb3oamrPQb","eventElapsedTime":"1.1909802777777363","eventTimestamp":"2023-04-22T20:30:06.482Z","eventCondition":"{phase} equals {str:0}","message":"Taxiing to gate, landed in 2467 ft"},{"eventId":"lhtbVaEXPqenVCuT","eventElapsedTime":"1.1985502777777357","eventTimestamp":"2023-04-22T20:30:33.734Z","eventCondition":"{flapsControl} changed","message":"Flaps set to 0%"},{"eventId":"JZRe5FqsKAOeRvHt","eventElapsedTime":"1.2077858333332905","eventTimestamp":"2023-04-22T20:31:06.982Z","eventCondition":"{engine1Firing} equals false","message":"Engine 1 Off"},{"eventId":"eQmoYsJ8UJGDXhic","eventElapsedTime":"1.208065277777735","eventTimestamp":"2023-04-22T20:31:07.989Z","eventCondition":"{phase} equals {str:0}","message":"Deboarding with a total flight time of {elapsedFlightTime}"}],"comments":"","aircraft":"106","flightTime":"1.1","route":["KDAL","KUSSO1","KUSSO","DCT","TRRCH","DCT","TRYTN","DCT","KTXK"]}

walkerairtrans commented 1 year ago

Just found the problem.

It seems that you are using the flight time from the schedule in our database instead of the app itself. This is not a good idea because my flight times are not valid nor used anywhere -- we allow pilots to use any type of plane they wish with any schedule we offer therefore that value is irrelevant. This is not the case in SC2, you send over the actual flight time from the app.

Original Post showing flight time 0.5 -- here it is in the schedule record. chrome_V0hTIErG7m

Here is the last comment with the data I provided from my test flight that should have been 58 minutes, not 1.1 hours. chrome_VcXBEKjgGn

Looks like you guys need to look at the app because it appears you are posting that flight time to us--it's not coming from the API files because I am intercepting your data before it even hits complete.php function.

jordanhavard commented 1 year ago

Nice write up @walkerairtrans I too was trying to figure out what was happening!

I can confirm this is also happening for me too. This is the last thing that needs addressing before I can start testing SC3 with our wider community 🎉

Thien42 commented 1 year ago

Will be fixed in the next update