Wie protokolliere ich die Ausführungszeit einer Methode genau in Millisekunden?

Gibt es eine Möglichkeit zu bestimmen, wie viel Zeit eine Methode zur Ausführung benötigt (in Millisekunden)?

NSDate *methodStart = [NSDate date];

/* ... Do whatever you need to do ... */

NSDate *methodFinish = [NSDate date];
NSTimeInterval executionTime = [methodFinish timeIntervalSinceDate:methodStart];
NSLog(@"executionTime = %f", executionTime);

Schnell:

let methodStart = NSDate()

/* ... Do whatever you need to do ... */

let methodFinish = NSDate()
let executionTime = methodFinish.timeIntervalSinceDate(methodStart)
print("Execution time: \(executionTime)")

Swift3:

let methodStart = Date()

/* ... Do whatever you need to do ... */

let methodFinish = Date()
let executionTime = methodFinish.timeIntervalSince(methodStart)
print("Execution time: \(executionTime)")

Einfach zu bedienen und mit einer Genauigkeit von weniger als einer Millisekunde.

Hier sind zwei einzeilige Makros, die ich verwende:

#define TICK   NSDate *startTime = [NSDate date]
#define TOCK   NSLog(@"Time: %f", -[startTime timeIntervalSinceNow])

Verwenden Sie es so:

TICK;

/* ... Do Some Work Here ... */

TOCK;

Für ein genaues Timing unter OS X sollten Sie mach_absolute_time( )deklariert in verwenden <mach/mach_time.h>:

#include <mach/mach_time.h>
#include <stdint.h>

// Do some stuff to setup for timing
const uint64_t startTime = mach_absolute_time();
// Do some stuff that you want to time
const uint64_t endTime = mach_absolute_time();

// Time elapsed in Mach time units.
const uint64_t elapsedMTU = endTime - startTime;

// Get information for converting from MTU to nanoseconds
mach_timebase_info_data_t info;
if (mach_timebase_info(&info))
   handleErrorConditionIfYoureBeingCareful();

// Get elapsed time in nanoseconds:
const double elapsedNS = (double)elapsedMTU * (double)info.numer / (double)info.denom;

Natürlich gelten die üblichen Vorbehalte gegen feinkörnige Messungen; Am besten rufen Sie die zu testende Routine am besten mehrmals auf und mitteln / nehmen ein Minimum / eine andere Form der Verarbeitung.

Beachten Sie außerdem, dass es möglicherweise nützlicher ist, Ihre Anwendung mit einem Tool wie Shark zu profilieren . Dadurch erhalten Sie keine genauen Timing-Informationen, aber es wird angezeigt, wie viel Prozent der Zeit der Anwendung wo verbracht wird, was häufig nützlicher ist (aber nicht immer).

Es gibt einen praktischen Wrapper für mach_absolute_time()- es ist eine CACurrentMediaTime()Funktion.

Im Gegensatz zu NSDateoder CFAbsoluteTimeGetCurrent()Offsets, mach_absolute_time()und CACurrentMediaTime()basieren auf der internen Host-Uhr, einem präzisen, einatomigen Maß, und unterliegen keinen Änderungen in der externen Zeitreferenz, wie sie beispielsweise durch Zeitzonen, Sommerzeit oder Schaltsekunden verursacht werden.

ObjC

CFTimeInterval startTime = CACurrentMediaTime();
// Do your stuff here
CFTimeInterval endTime = CACurrentMediaTime();
NSLog(@"Total Runtime: %g s", endTime - startTime);

Schnell

let startTime = CACurrentMediaTime()
// Do your stuff here
let endTime = CACurrentMediaTime()
print("Total Runtime: \(endTime - startTime) s")

In Swift verwende ich:

In meinem Macros.swift habe ich gerade hinzugefügt

var startTime = NSDate()
func TICK(){ startTime =  NSDate() }
func TOCK(function: String = __FUNCTION__, file: String = __FILE__, line: Int = __LINE__){
    println("\(function) Time: \(startTime.timeIntervalSinceNow)\nLine:\(line) File: \(file)")
}

Sie können jetzt einfach überall anrufen

TICK()

// your code to be tracked

TOCK()

• Dieser Code basiert auf Rons Code, der in Swift übersetzt wurde. Er hat die Credits
• Ich verwende das Startdatum auf globaler Ebene. Vorschläge zur Verbesserung sind willkommen

Ich weiß, dass dies eine alte ist, aber selbst ich bin wieder daran vorbeigekommen, also dachte ich, ich würde hier meine eigene Option einreichen.

Am besten schau dir meinen Blog-Beitrag dazu an: Timing der Dinge in Objective-C: Eine Stoppuhr

Grundsätzlich habe ich eine Klasse geschrieben, die auf sehr einfache Weise aufhört zu schauen, aber gekapselt ist, sodass Sie nur Folgendes tun müssen:

[MMStopwatchARC start:@"My Timer"];
// your work here ...
[MMStopwatchARC stop:@"My Timer"];

Und am Ende haben Sie:

MyApp[4090:15203]  -> Stopwatch: [My Timer] runtime: [0.029]

im Protokoll ...

Schauen Sie sich meinen Beitrag noch einmal an oder laden Sie ihn hier herunter: MMStopwatch.zip

Ich benutze Makros basierend auf Rons Lösung.

#define TICK(XXX) NSDate *XXX = [NSDate date]
#define TOCK(XXX) NSLog(@"%s: %f", #XXX, -[XXX timeIntervalSinceNow])

Für Codezeilen:

TICK(TIME1);
/// do job here
TOCK(TIME1);

Wir werden in der Konsole etwas sehen wie: TIME1: 0.096618

Ich verwende eine sehr minimale Implementierung einer Seitenklasse, die vom Code aus diesem Blog-Beitrag inspiriert ist :

#import <mach/mach_time.h>

@interface DBGStopwatch : NSObject

+ (void)start:(NSString *)name;
+ (void)stop:(NSString *)name;

@end

@implementation DBGStopwatch

+ (NSMutableDictionary *)watches {
    static NSMutableDictionary *Watches = nil;
    static dispatch_once_t OnceToken;
    dispatch_once(&OnceToken, ^{
        Watches = @{}.mutableCopy;
    });
    return Watches;
}

+ (double)secondsFromMachTime:(uint64_t)time {
    mach_timebase_info_data_t timebase;
    mach_timebase_info(&timebase);
    return (double)time * (double)timebase.numer /
        (double)timebase.denom / 1e9;
}

+ (void)start:(NSString *)name {
    uint64_t begin = mach_absolute_time();
    self.watches[name] = @(begin);
}

+ (void)stop:(NSString *)name {
    uint64_t end = mach_absolute_time();
    uint64_t begin = [self.watches[name] unsignedLongLongValue];
    DDLogInfo(@"Time taken for %@ %g s",
              name, [self secondsFromMachTime:(end - begin)]);
    [self.watches removeObjectForKey:name];
}

@end

Die Verwendung ist sehr einfach:

• Rufen Sie einfach [DBGStopwatch start:@"slow-operation"];am Anfang an
• und dann [DBGStopwatch stop:@"slow-operation"];nach dem Ziel, um die Zeit zu bekommen

Mit dieser StopWatch-Klasse können Sie ein wirklich feines Timing (Sekunden, Sekunden) erzielen. Es verwendet den hochpräzisen Timer im iPhone. Wenn Sie NSDate verwenden, erhalten Sie nur eine Sekunde (n) Genauigkeit. Diese Version wurde speziell für Autorelease und Objective-C entwickelt. Bei Bedarf habe ich auch eine C ++ - Version. Die c ++ - Version finden Sie hier .

StopWatch.h

#import <Foundation/Foundation.h>


@interface StopWatch : NSObject 
{
    uint64_t _start;
    uint64_t _stop;
    uint64_t _elapsed;
}

-(void) Start;
-(void) Stop;
-(void) StopWithContext:(NSString*) context;
-(double) seconds;
-(NSString*) description;
+(StopWatch*) stopWatch;
-(StopWatch*) init;
@end

StopWatch.m

#import "StopWatch.h"
#include <mach/mach_time.h>

@implementation StopWatch

-(void) Start
{
    _stop = 0;
    _elapsed = 0;
    _start = mach_absolute_time();
}
-(void) Stop
{
    _stop = mach_absolute_time();   
    if(_stop > _start)
    {
        _elapsed = _stop - _start;
    }
    else 
    {
        _elapsed = 0;
    }
    _start = mach_absolute_time();
}

-(void) StopWithContext:(NSString*) context
{
    _stop = mach_absolute_time();   
    if(_stop > _start)
    {
        _elapsed = _stop - _start;
    }
    else 
    {
        _elapsed = 0;
    }
    NSLog([NSString stringWithFormat:@"[%@] Stopped at %f",context,[self seconds]]);

    _start = mach_absolute_time();
}


-(double) seconds
{
    if(_elapsed > 0)
    {
        uint64_t elapsedTimeNano = 0;

        mach_timebase_info_data_t timeBaseInfo;
        mach_timebase_info(&timeBaseInfo);
        elapsedTimeNano = _elapsed * timeBaseInfo.numer / timeBaseInfo.denom;
        double elapsedSeconds = elapsedTimeNano * 1.0E-9;
        return elapsedSeconds;
    }
    return 0.0;
}
-(NSString*) description
{
    return [NSString stringWithFormat:@"%f secs.",[self seconds]];
}
+(StopWatch*) stopWatch
{
    StopWatch* obj = [[[StopWatch alloc] init] autorelease];
    return obj;
}
-(StopWatch*) init
{
    [super   init];
    return self;
}

@end

Die Klasse hat eine statische stopWatch Methode, die ein automatisch freigegebenes Objekt zurückgibt.

startVerwenden Sie nach dem Aufruf die secondsMethode, um die verstrichene Zeit abzurufen. Rufen Sie starterneut auf, um es neu zu starten. Oder stopum es zu stoppen. Sie können die Uhrzeit (Anruf seconds) jederzeit nach dem Anruf ablesen stop.

Beispiel in einer Funktion (Timing-Aufruf der Ausführung)

-(void)SomeFunc
{
   StopWatch* stopWatch = [StopWatch stopWatch];
   [stopWatch Start];

   ... do stuff

   [stopWatch StopWithContext:[NSString stringWithFormat:@"Created %d Records",[records count]]];
}

Ich benutze diesen Code:

#import <mach/mach_time.h>

float TIME_BLOCK(NSString *key, void (^block)(void)) {
    mach_timebase_info_data_t info;
    if (mach_timebase_info(&info) != KERN_SUCCESS)
    {
        return -1.0;
    }

    uint64_t start = mach_absolute_time();
    block();
    uint64_t end = mach_absolute_time();
    uint64_t elapsed = end - start;

    uint64_t nanos = elapsed * info.numer / info.denom;
    float cost = (float)nanos / NSEC_PER_SEC;

    NSLog(@"key: %@ (%f ms)\n", key, cost * 1000);
    return cost;
}

Ich benutze das:

clock_t start, end;
double elapsed;
start = clock();

//Start code to time

//End code to time

end = clock();
elapsed = ((double) (end - start)) / CLOCKS_PER_SEC;
NSLog(@"Time: %f",elapsed);

Bei CLOCKS_PER_SEC auf dem iPhone bin ich mir jedoch nicht sicher. Vielleicht möchten Sie es weglassen.

Ein Beispiel für ein feinkörniges Timing mach_absolute_time()in Swift 4:

let start = mach_absolute_time()

// do something

let elapsedMTU = mach_absolute_time() - start
var timebase = mach_timebase_info()
if mach_timebase_info(&timebase) == 0 {
    let elapsed = Double(elapsedMTU) * Double(timebase.numer) / Double(timebase.denom)
    print("render took \(elapsed)")
}
else {
    print("timebase error")
}

OK, wenn Ihr Ziel darin besteht, herauszufinden, was Sie beheben können, um es schneller zu machen, ist das ein etwas anderes Ziel. Das Messen der Zeit, die Funktionen benötigen , ist ein guter Weg, um herauszufinden, ob das, was Sie getan haben, einen Unterschied gemacht hat, aber um herauszufinden, was zu tun ist , benötigen Sie eine andere Technik. Das empfehle ich , und ich weiß, dass Sie es auf iPhones tun können.

Bearbeiten: Die Rezensenten schlugen vor, die Antwort auszuarbeiten, daher versuche ich, eine kurze Möglichkeit zu finden, sie auszudrücken.
Ihr Gesamtprogramm benötigt genügend Zeit, um Sie zu stören. Angenommen, das sind N Sekunden.
Sie gehen davon aus, dass Sie es beschleunigen können. Die einzige Möglichkeit, dies zu tun, besteht darin, dafür zu sorgen, dass es in dieser Zeit nichts tut, was m Sekunden entspricht.
Sie wissen zunächst nicht, was das für ein Ding ist. Sie können raten, wie alle Programmierer, aber es könnte leicht etwas anderes sein. Was auch immer es ist, so finden Sie es:

Da dieses Ding, was auch immer es ist, einen Bruchteil m / N der Zeit ausmacht, bedeutet das, wenn Sie es zufällig anhalten, ist die Wahrscheinlichkeit m / N, dass Sie es beim Handeln erwischen. Natürlich könnte es etwas anderes tun, aber halten Sie es an und sehen Sie, was es tut.
Jetzt mach es nochmal. Wenn Sie sehen, dass es wieder dasselbe tut, können Sie misstrauischer sein.

Tun Sie es 10 Mal oder 20. Wenn Sie nun sehen, dass es in mehreren Pausen eine bestimmte Sache tut (egal wie Sie es beschreiben), die Sie loswerden können, wissen Sie zwei Dinge. Sie wissen sehr genau, wie viel Zeit es dauert, aber Sie wissen sehr genau, was zu beheben ist.
Wenn Sie auch genau wissen möchten, wie viel Zeit gespart wird, ist das ganz einfach. Messen Sie es vorher, reparieren Sie es und messen Sie es danach. Wenn Sie wirklich enttäuscht sind, ziehen Sie das Update zurück.

Sehen Sie, wie sich das vom Messen unterscheidet? Es findet, nicht messen . Die meisten Profile basieren darauf, so genau wie möglich zu messen, wie viel Zeit benötigt wird, als ob dies wichtig wäre, und das Problem der Identifizierung der zu behebenden Probleme von Hand zu lösen. Die Profilerstellung findet nicht jedes Problem, aber diese Methode findet jedes Problem, und es sind die Probleme, die Sie nicht finden, die Sie verletzen.

In Swift gibt es eine andere Möglichkeit, dies mit dem Schlüsselwort defer zu tun

func methodName() {
  let methodStart = Date()
  defer {
    let executionTime = Date().timeIntervalSince(methodStart)
    print("Execution time: \(executionTime)")
  }
  // do your stuff here
}

Aus Apples Dokumenten : Eine Defer-Anweisung wird zum Ausführen von Code verwendet, bevor die Programmsteuerung außerhalb des Bereichs übertragen wird, in dem die Defer-Anweisung angezeigt wird.

Dies ähnelt einem try / finally-Block mit dem Vorteil, dass der zugehörige Code gruppiert wird.

Ich benutze dies in meiner Utils-Bibliothek ( Swift 4.2 ):

public class PrintTimer {
    let start = Date()
    let name: String

    public init(file: String=#file, line: Int=#line, function: String=#function, name: String?=nil) {
        let file = file.split(separator: "/").last!
        self.name = name ?? "\(file):\(line) - \(function)"
    }

    public func done() {
        let end = Date()
        print("\(self.name) took \((end.timeIntervalSinceReferenceDate - self.start.timeIntervalSinceReferenceDate).roundToSigFigs(5)) s.")
    }
}

... rufen Sie dann eine Methode auf wie:

func myFunctionCall() {
    let timer = PrintTimer()
    // ...
    timer.done()
}

... was wiederum in der Konsole nach dem Ausführen so aussieht:

MyFile.swift:225 - myFunctionCall() took 1.8623 s.

Nicht so präzise wie TICK / TOCK oben, aber es ist klar genug, um zu sehen, was es tut, und es enthält automatisch, was zeitlich festgelegt wird (nach Datei, Zeile am Anfang der Methode und Funktionsname). Wenn ich mehr Details haben möchte (z. B. wenn ich nicht nur einen Methodenaufruf wie üblich zeitlich terminiere, sondern stattdessen einen Block innerhalb dieser Methode terminiere), kann ich den Parameter "name =" Foo "" auf dem PrintTimer-Init hinzufügen um es etwas anderes als die Standardeinstellungen zu nennen.

Bedeutet dies nicht, dass Sie das beim Laden dieser Seiten verwendete Javascript wirklich optimieren möchten, da Sie die Zeit für den Wechsel von einer Seite zur anderen in einer UIWebView optimieren möchten?

Zu diesem Zweck würde ich mir einen WebKit-Profiler ansehen, über den hier gesprochen wurde:

http://www.alertdebugging.com/2009/04/29/building-a-better-javascript-profiler-with-webkit/

Ein anderer Ansatz wäre, auf einer hohen Ebene zu beginnen und zu überlegen, wie Sie die betreffenden Webseiten so gestalten können, dass die Ladezeiten beim Laden von Seiten im AJAX-Stil minimiert werden, anstatt jedes Mal die gesamte Webansicht zu aktualisieren.

struct TIME {

    static var ti = mach_timebase_info()
    static var k: Double = 1
    static var mach_stamp: Double {

        if ti.denom == 0 {
            mach_timebase_info(&ti)
            k = Double(ti.numer) / Double(ti.denom) * 1e-6
        }
        return Double(mach_absolute_time()) * k
    }
    static var stamp: Double { return NSDate.timeIntervalSinceReferenceDate() * 1000 }
}

do {
    let mach_start = TIME.mach_stamp
    usleep(200000)
    let mach_diff = TIME.mach_stamp - mach_start

    let start = TIME.stamp
    usleep(200000)
    let diff = TIME.stamp - start

    print(mach_diff, diff)
}

Hier ist eine Swift 3-Lösung, mit der Sie Code überall halbieren können, um einen lang laufenden Prozess zu finden.

var increment: Int = 0

var incrementTime = NSDate()

struct Instrumentation {
    var title: String
    var point: Int
    var elapsedTime: Double

    init(_ title: String, _ point: Int, _ elapsedTime: Double) {
        self.title = title
        self.point = point
        self.elapsedTime = elapsedTime
    }
}

var elapsedTimes = [Instrumentation]()

func instrument(_ title: String) {
    increment += 1
    let incrementedTime = -incrementTime.timeIntervalSinceNow
    let newPoint = Instrumentation(title, increment, incrementedTime)
    elapsedTimes.append(newPoint)
    incrementTime = NSDate()
}

Verwendung: -

instrument("View Did Appear")

print("ELAPSED TIMES \(elapsedTimes)")

Beispielausgabe: -

ELAPSED TIMES [MyApp.SomeViewController.Instrumentation (Titel: "Start View Did Load", Punkt: 1, elapsedTime: 0.040504038333892822), MyApp.SomeViewController.Instrumentation (Titel: "Finished Adding SubViews", Punkt: 2, elapsedTime: 5175) MyApp.SomeViewController.Instrumentation (Titel: "View Did Appeared", Punkt: 3, elapsedTime: 0.56564098596572876)]

Viele Antworten sind seltsam und geben nicht wirklich Ergebnisse in Millisekunden (aber in Sekunden oder irgendetwas anderem):

hier was ich benutze um MS zu bekommen (MILLISECONDS):

Schnell:

let startTime = NSDate().timeIntervalSince1970 * 1000

// your Swift code

let endTimeMinusStartTime = NSDate().timeIntervalSince1970 * 1000 - startTime
print("time code execution \(endTimeMinStartTime) ms")

Ziel c:

double startTime = [[NSDate date] timeIntervalSince1970] * 1000.0;

// your Objective-C code

double endTimeMinusStartTime = [[NSDate date] timeIntervalSince1970] * 1000.0 - startTime;
printf("time code execution %f ms\n", endTimeMinusStartTime );

Fügen Sie für Swift 4 Ihrer Klasse einen Delegierten hinzu:

public protocol TimingDelegate: class {
    var _TICK: Date?{ get set }
}

extension TimingDelegate {
    var TICK: Date {
        _TICK = Date()
        return(_TICK)!
     }

    func TOCK(message: String)  {

        if (_TICK == nil){
            print("Call 'TICK' first!")
        }

        if (message == ""){
            print("\(Date().timeIntervalSince(_TICK!))")
        }
        else{
            print("\(message): \(Date().timeIntervalSince(_TICK!))")
        }
    }
}

Zu unserer Klasse hinzufügen:

class MyViewcontroller: UIViewController, TimingDelegate

Fügen Sie dann Ihrer Klasse hinzu:

var _TICK: Date?

Wenn Sie etwas zeitlich festlegen möchten, beginnen Sie mit:

TICK

Und ende mit:

TOCK("Timing the XXX routine")