brnstz
commented
8 years ago Timing from a sample request:
It looks like the biggest time waster is setDepartures / getVehicles. Calculate stop.go:242 - stop.go:86 and you get very little.
stop.go:242 = total time getting an individual stop and its departures
stop.go:276 = total time in models getting all stops for lat/lon query
stop.go:349 = getting service ids
stop.go:86 = setting departures for a stop (and getting vehicles inside)
vehicle.go:60 = getting all vehicles for a route
stop.go:242: 101.054102ms
stop.go:242: 102.651786ms
stop.go:242: 103.596311ms
stop.go:242: 103.886525ms
stop.go:242: 142.680684ms
stop.go:242: 152.159148ms
stop.go:242: 159.578599ms
stop.go:242: 164.238288ms
stop.go:242: 176.657679ms
stop.go:242: 32.361041ms
stop.go:242: 33.050688ms
stop.go:242: 94.304052ms
stop.go:276: 1.40755656s
stop.go:292: 40.907768ms
stop.go:349: 1.394173ms
stop.go:349: 1.420809ms
stop.go:349: 1.433278ms
stop.go:349: 1.455079ms
stop.go:349: 1.459912ms
stop.go:349: 1.464805ms
stop.go:349: 1.494092ms
stop.go:349: 1.532804ms
stop.go:349: 1.572603ms
stop.go:349: 1.604806ms
stop.go:349: 1.645968ms
stop.go:349: 1.665478ms
stop.go:349: 1.672452ms
stop.go:349: 1.681059ms
stop.go:349: 1.68359ms
stop.go:349: 1.705375ms
stop.go:349: 1.727503ms
stop.go:349: 1.772465ms
stop.go:349: 1.804858ms
stop.go:349: 1.816676ms
stop.go:349: 1.913001ms
stop.go:349: 2.307562ms
stop.go:349: 2.600012ms
stop.go:349: 5.475689ms
stop.go:86: 100.472001ms
stop.go:86: 101.982312ms
stop.go:86: 102.917377ms
stop.go:86: 103.223803ms
stop.go:86: 140.337978ms
stop.go:86: 151.471472ms
stop.go:86: 158.926554ms
stop.go:86: 163.669546ms
stop.go:86: 176.020169ms
stop.go:86: 31.756526ms
stop.go:86: 32.460333ms
stop.go:86: 93.095283ms
vehicle.go:26: 1.197289ms
vehicle.go:26: 1.438158ms
vehicle.go:26: 538.664µs
vehicle.go:26: 549.771µs
vehicle.go:26: 568.795µs
vehicle.go:26: 571.64µs
vehicle.go:26: 575.522µs
vehicle.go:26: 579.02µs
vehicle.go:26: 581.268µs
vehicle.go:26: 585.044µs
vehicle.go:26: 587.522µs
vehicle.go:26: 591.002µs
vehicle.go:26: 591.081µs
vehicle.go:26: 603.533µs
vehicle.go:26: 606.879µs
vehicle.go:26: 610.988µs
vehicle.go:26: 614.955µs
vehicle.go:26: 618.113µs
vehicle.go:26: 627.484µs
vehicle.go:26: 634.827µs
vehicle.go:26: 638.326µs
vehicle.go:26: 642.305µs
vehicle.go:26: 674.904µs
vehicle.go:26: 690.387µs
vehicle.go:26: 708.69µs
vehicle.go:26: 712.272µs
vehicle.go:26: 756.294µs
vehicle.go:26: 773.622µs
vehicle.go:60: 11.595829ms
vehicle.go:60: 11.63605ms
vehicle.go:60: 15.502717ms
vehicle.go:60: 16.207241ms
vehicle.go:60: 27.915572ms
vehicle.go:60: 37.204916ms
vehicle.go:60: 41.357365ms
vehicle.go:60: 41.732179ms
vehicle.go:60: 41.823749ms
vehicle.go:60: 49.378029ms
vehicle.go:60: 54.155249ms
vehicle.go:60: 54.287825ms
vehicle.go:60: 55.097646ms
vehicle.go:60: 55.479861ms
vehicle.go:60: 60.334686ms
vehicle.go:60: 62.115208ms
vehicle.go:60: 70.421248ms
vehicle.go:60: 70.832075ms
vehicle.go:60: 75.385514ms
vehicle.go:60: 83.116941ms
vehicle.go:60: 84.503307ms
vehicle.go:60: 87.590556ms
vehicle.go:60: 88.12927ms
vehicle.go:60: 93.07658ms
Each query to load a stop takes ~100ms, so even with just 10 stops it can be up to a second. The query to figure out which stops is not especially long, it's that we then have to requery db for each stop serially. Either need to do this with concurrent queries or single query.