Advertise Mobile SDKs Books Events Forum News Social Networking Support Us
Follow @iphonedevsdk on Twitter

Interface 2, Advanced iOS
Mockup & Code Gen
($9.99)

Make your own iPhone apps
and run them live!
(free)

Pic Frame Dynamo: Photo Editing
($0.99)

Abiliator
($1.99)

Want your application or service advertised on iPhone Dev SDK?

Go Back   iPhone Dev SDK Forum > iPhone SDK Development Forums > iPhone SDK Development

Reply
 
LinkBack Thread Tools Display Modes
Old 05-26-2011, 04:51 AM   #1 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default iphone command time of 9ms ?!?!

hi , i put this in the viewdidload :

Code:
start = [[NSDate date] retain]; 
    NSLog(@"start");
    duration = [start timeIntervalSinceNow] * -1000.0;
    NSLog(@"%f", duration);
i get this on simulation on the mac :

Code:
2011-05-26 17:41:46.165 MicBlow[7149:207] start
2011-05-26 17:41:46.166 MicBlow[7149:207] 0.970006
and this on the iphone simulation(connected) !!! :

Code:
2011-05-26 12:38:27.663 MicBlow[4066:707] start
2011-05-26 12:38:27.672 MicBlow[4066:707] 9.421051
what is that ?! 9msec for 2 commands? 1msec ?! and so big different between iphone and simulation ?? isnt the iphone has a processor of about 1ghz ?!

i have to say that i have got the same number when putting it anywhere on my code ....

any explanation ?
thanks.
R2RG is offline   Reply With Quote
Old 05-26-2011, 06:15 AM   #2 (permalink)
Nuisance Developer
 
Join Date: Jul 2009
Location: Italy
Posts: 4,691
dany_dev is on a distinguished road
Default

consider that the code is running on debug mode......so I don't think that there is some problems....
__________________
dany_dev is offline   Reply With Quote
Old 05-26-2011, 06:43 AM   #3 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default what ?

Quote:
Originally Posted by dany_dev View Post
consider that the code is running on debug mode......so I don't think that there is some problems....
What?
i dont understand your answer...

THERE is a problem, that the command time is not right,
THERE is a problem that there is a 9ms gap between iphone and simulation.

i cant see how you solved that ..
R2RG is offline   Reply With Quote
Old 05-26-2011, 06:44 AM   #4 (permalink)
Registered Member
 
Join Date: May 2010
Location: London
Posts: 90
Renaissance77 is on a distinguished road
Default

NSLog() calls are very slow, especially when you're debugging.
Renaissance77 is offline   Reply With Quote
Old 05-26-2011, 06:44 AM   #5 (permalink)
Reading the Documentation
 
baja_yu's Avatar
 
Join Date: Sep 2010
Location: 45.255019,19.844908
Posts: 5,414
baja_yu has a spectacular aura about
Default

NSLog on its own is quite slow as well.
baja_yu is offline   Reply With Quote
Old 05-26-2011, 06:59 AM   #6 (permalink)
Cocoa Junkie
 
Duncan C's Avatar
 
Join Date: Dec 2008
Location: Northern Virginia
Posts: 6,003
Duncan C has a spectacular aura about
Default

Quote:
Originally Posted by R2RG View Post
hi , i put this in the viewdidload :

Code:
start = [[NSDate date] retain]; 
    NSLog(@"start");
    duration = [start timeIntervalSinceNow] * -1000.0;
    NSLog(@"%f", duration);
i get this on simulation on the mac :

Code:
2011-05-26 17:41:46.165 MicBlow[7149:207] start
2011-05-26 17:41:46.166 MicBlow[7149:207] 0.970006
and this on the iphone simulation(connected) !!! :

Code:
2011-05-26 12:38:27.663 MicBlow[4066:707] start
2011-05-26 12:38:27.672 MicBlow[4066:707] 9.421051
what is that ?! 9msec for 2 commands? 1msec ?! and so big different between iphone and simulation ?? isnt the iphone has a processor of about 1ghz ?!

i have to say that i have got the same number when putting it anywhere on my code ....

any explanation ?
thanks.

It's the log statement. Those are very slow. Try collecting the timing information and then generating the log statements after it's all done.
__________________
Regards,

Duncan C
WareTo

Check out our apps in the Apple App store


Check out this password generator app that shows various techniques including using a data container singleton object to share data between objects in your project.

See this tutorial on using UIView animations and layer animations:

See this thread on generating random, non-repeating text

Check out a very cool Macintosh Kaleidoscopes app called ScopeWorks that we released to the Mac App store.
Duncan C is offline   Reply With Quote
Old 05-26-2011, 07:38 AM   #7 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default got it

Quote:
Originally Posted by R2RG View Post
What?
i dont understand your answer...

THERE is a problem, that the command time is not right,
THERE is a problem that there is a 9ms gap between iphone and simulation.

i cant see how you solved that ..

i have got it.

[recorder stop] is take so much time !

i need to get audio input without recording.
any suggestion ?
R2RG is offline   Reply With Quote
Old 05-26-2011, 09:46 AM   #8 (permalink)
Token farm animal
 
sneaky's Avatar
 
Join Date: Apr 2011
Posts: 321
sneaky is on a distinguished road
Default

I was actually corrected on this just recently. Use mach_absolute_time() from <mach/mach_time.h> instead of NSDate as NSDate can compensate back and forwards a small bit. NSDate is not accurate enough to be used for this type of measurement.
sneaky is offline   Reply With Quote
Old 05-27-2011, 09:29 AM   #9 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default thanks for the answers

ok i have to understand a few things.

1. the fact that nslog is slow, does not have to be counted ,because the relations between 2 logs is still the same.. so even if it takes time to get them, the relations between 2 points still the same BUT i get them not in real time ?? otherwise, whats the benefits from NSLog ?

2. if the times on debugging are not accurate, so how one's can do a more accurate debugging stuff ?

3. i was told that NSDATE is very accurate,and i could see that NSDate and NSLog are match exactly ,and gives me good answer,when simulating on the mac without the iphone. so i guess its another problem?

4. i have seen that when i turn the recorder on, and check for the times, i get that it takes a few msec to turn it on and off each cycle.
the reason that i turn it on and off all time, is that if you put it ON all time, you cant measure anything because iphone see audio input for not less than 900ms, even if the input signal was just 100ms. thats its mechanism .

so any idea, on how to measure times in real time and not being blind ?!
or get audio input in real time? with/without recording ?

thanks a lot for your answers.

.
R2RG is offline   Reply With Quote
Old 05-27-2011, 09:50 AM   #10 (permalink)
Cocoa Junkie
 
Duncan C's Avatar
 
Join Date: Dec 2008
Location: Northern Virginia
Posts: 6,003
Duncan C has a spectacular aura about
Default

Quote:
Originally Posted by R2RG View Post
ok i have to understand a few things.

1. the fact that nslog is slow, does not have to be counted ,because the relations between 2 logs is still the same.. so even if it takes time to get them, the relations between 2 points still the same BUT i get them not in real time ?? otherwise, whats the benefits from NSLog ?

2. if the times on debugging are not accurate, so how one's can do a more accurate debugging stuff ?

3. i was told that NSDATE is very accurate,and i could see that NSDate and NSLog are match exactly ,and gives me good answer,when simulating on the mac without the iphone. so i guess its another problem?

4. i have seen that when i turn the recorder on, and check for the times, i get that it takes a few msec to turn it on and off each cycle.
the reason that i turn it on and off all time, is that if you put it ON all time, you cant measure anything because iphone see audio input for not less than 900ms, even if the input signal was just 100ms. thats its mechanism .

so any idea, on how to measure times in real time and not being blind ?!
or get audio input in real time? with/without recording ?

thanks a lot for your answers.

.

Come on man, think. NSLog is slow. Really, really slow on the device, but also slow on the simulator. Don't put NSLog statements inside code you are trying to time. Collect results in variables, and then log those results once you are done collecting time information. Something like this.


Code:
NSTimeInterval 
  startTime, 
  firstElapsedTime, 
  secondElapsedTime,
  thirdElapsedTime;

startTime = [NSDate timeIntervalSinceReferenceDate];
//do stuff that we want to time.
firstElapsedTime = [NSDate timeIntervalSinceReferenceDate] - startTime;

startTime = [NSDate timeIntervalSinceReferenceDate];
//Do something else that we want to time
secondElapsedTime = [NSDate timeIntervalSinceReferenceDate] - startTime;

startTime = [NSDate timeIntervalSinceReferenceDate];
//Do yet a third thing that we want to time
thirdElapsedTime = [NSDate timeIntervalSinceReferenceDate] - startTime;


NSLog(@"The first timed code took %f seconds", firstElapsedTime);
NSLog(@"The second timed code took %f seconds", secondElapsedTime);
NSLog(@"The third timed code took %f seconds", thirdElapsedTime);

Note how that code collects all the timing information without issuing a single NSLog command, and then logs the results once all the time-critical code is done.

I also use NSTimeInterval values to record start and end times so I don't have to worry about creating and releasing NSDate objects. If you make the time interval variables instance variables, you can use the approach above to time asynchronous events like network downloads.
__________________
Regards,

Duncan C
WareTo

Check out our apps in the Apple App store


Check out this password generator app that shows various techniques including using a data container singleton object to share data between objects in your project.

See this tutorial on using UIView animations and layer animations:

See this thread on generating random, non-repeating text

Check out a very cool Macintosh Kaleidoscopes app called ScopeWorks that we released to the Mac App store.
Duncan C is offline   Reply With Quote
Old 05-27-2011, 10:32 AM   #11 (permalink)
Registered Member
 
Join Date: Nov 2010
Posts: 1,106
Meredi86 is on a distinguished road
Default

Quote:
1. the fact that nslog is slow, does not have to be counted ,because the relations between 2 logs is still the same.. so even if it takes time to get them, the relations between 2 points still the same BUT i get them not in real time ?? otherwise, whats the benefits from NSLog
I would assume that NSLog is like every single other command that a computer runs. By this i mean that it isnt going to take EXACTLY the same time to execute every time you run it.

Apart from the intricate details that are beyond me think about the other factors that affect both the simulator and the phone. Are there other programs running in the background? Has some flash just loaded on a webpage? Have you opened up another App? Has your HD spun up to access data? Have you filled your RAM a bit more? iIs your phone off to get some mail? All of these things are going to alter the time it takes for an NSLog and anything else to execute (though i think its possible to reserve resources in some situations - not sure about on the phone though - may need correcting there). If you are thinking differently then open up activity monitor and have a look at all of the constantly changing numbers.

I would say that NSLog is fairly accurate, and for less time sensitive issues it wouldnt be a problem - i sometimes use it to gain an average download time when im in development, log each element value returned, get 10 readings (from start of download to finish) and take an average. Its not going to give me a true figure for how long the download takes, but it will give me an idea and ill be able to see any improvements in my code from it. To go more detailed i would look for Duncans answer.

Oh and is that a 9ms time on an iPhone 4? 3Gs, 3G, or before? Because that will also alter that timeframe.
Meredi86 is offline   Reply With Quote
Old 05-27-2011, 02:40 PM   #12 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default thanks BUT

What you say here is not relevant, because i dont care from the NSLog times, because the NSDate should be accurate, and he gets the time interval INSIDE the iphone, so it doesnt matter when do i get them on the log, the interval between 2 points inside an iphone should be accurate...

I mean, the NSDate interval should be accurate even if i get him not in real time, its the relation between 2 times that is intresting me ..

so how come that i get 9ms ?? this doesnt have to do anything with NSLog !

What was wrong here ?

how anyway one can get real time ???
R2RG is offline   Reply With Quote
Old 05-27-2011, 02:44 PM   #13 (permalink)
Reading the Documentation
 
baja_yu's Avatar
 
Join Date: Sep 2010
Location: 45.255019,19.844908
Posts: 5,414
baja_yu has a spectacular aura about
Default

It has everything to do with NSLog and other stuff you do between the two points where you get the current time. How is this not getting through? Let's say I tell you to look at your watch and record the time, then look at it again and record the time and calculate the difference. Then imagine that before I tell you to record the second time I tell you to first move a pile of bricks 100 yards away. Do you think that wouldn't have any effect on the time difference?

And what do you mean by "real time"?!
baja_yu is offline   Reply With Quote
Old 05-27-2011, 03:26 PM   #14 (permalink)
Cocoa Junkie
 
Duncan C's Avatar
 
Join Date: Dec 2008
Location: Northern Virginia
Posts: 6,003
Duncan C has a spectacular aura about
Default

Quote:
Originally Posted by R2RG View Post
What you say here is not relevant, because i dont care from the NSLog times, because the NSDate should be accurate, and he gets the time interval INSIDE the iphone, so it doesnt matter when do i get them on the log, the interval between 2 points inside an iphone should be accurate...

I mean, the NSDate interval should be accurate even if i get him not in real time, its the relation between 2 times that is intresting me ..

so how come that i get 9ms ?? this doesnt have to do anything with NSLog !

What was wrong here ?

how anyway one can get real time ???

Dude, you are not listening to what we are telling you. I'm going to try one last time. Compare the two blocks below carefully. Compile the second code and actually try it.

Here is the code you posted:


Code:
start = [[NSDate date] retain]; 
//The log statement appears between the start and end times
//Thus, the time includes the amount of time it takes to execute the log statement
NSLog(@"start");  
duration = [start timeIntervalSinceNow] * -1000.0;
NSLog(@"%f", duration);
Your code is measuring how long it takes to generate the log statement.

If we rewrite your code slightly, the time won't include the amount of time required to generate the log statement:


Code:
NSLog(@"start");  
start = [[NSDate date] retain]; 
duration = [start timeIntervalSinceNow] * -1000.0;
NSLog(@"%f", duration);


With the second block of code, you're not measuring the time it takes to generate the log statement, WHICH IS VERY SLOW. Did you get that part? Log statements are slow. Don't include a log statement between the time you start measuring and the time you end measuring. It throws off your results, DRAMATICALLY.
__________________
Regards,

Duncan C
WareTo

Check out our apps in the Apple App store


Check out this password generator app that shows various techniques including using a data container singleton object to share data between objects in your project.

See this tutorial on using UIView animations and layer animations:

See this thread on generating random, non-repeating text

Check out a very cool Macintosh Kaleidoscopes app called ScopeWorks that we released to the Mac App store.
Duncan C is offline   Reply With Quote
Old 05-27-2011, 03:36 PM   #15 (permalink)
Token farm animal
 
sneaky's Avatar
 
Join Date: Apr 2011
Posts: 321
sneaky is on a distinguished road
Default

NSLog is notoriously slow, really!

Your Mac is quite a lot faster than your iOS device and will have resources just ready to go for such a trivial request. Can you please just try Duncan's code sample above - without adding any NSLogging or anything else, just as it is. Then add a NSLog between every time sample. What do you observe?

You are obviously not interested in how fast you can log "start" to the console. What are you actually trying to do here?

mid air collision
Edit: I meant the earlier code sample...

Last edited by sneaky; 05-27-2011 at 03:38 PM.
sneaky is offline   Reply With Quote
Old 05-27-2011, 04:32 PM   #16 (permalink)
Registered Member
 
Join Date: May 2011
Posts: 32
R2RG is on a distinguished road
Default wow !

WOW !
now i have got you !
The NSLog itself takes too much time !

i was thinking that you talked about the time it takes to write from the usb cable of the iphone , to the computer !! ( i am electrical engineer )

so you say that nslog command takes time when debugging with the iphone, and also when only simulation ? .... mmmm...

thanks a lot guys !!

if i wasnt here, i couldnt mention this for ever !!

this is the second time you really help me...
AND save my job !

thanks a lot for answer my stupid questions... !
R2RG is offline   Reply With Quote
Old 05-27-2011, 05:27 PM   #17 (permalink)
Senior Member
iPhone Dev SDK Supporter
 
Join Date: Jan 2010
Location: Issaquah, WA
Age: 42
Posts: 1,244
dljeffery is on a distinguished road
Default

Side note: There is absolutely no reason (at least in the code you've given) to retain your NSDate. I only mention this to save you from memory leakage hassles down the road... especially since you don't show where you release it.
__________________
Recall It! Tag your notes. Tag your photos. Tag your thoughts. Tag your life.

Recall It! for iPad

http://www.dljeffery.com
dljeffery is offline   Reply With Quote
Old 05-27-2011, 06:55 PM   #18 (permalink)
Cocoa Junkie
 
Duncan C's Avatar
 
Join Date: Dec 2008
Location: Northern Virginia
Posts: 6,003
Duncan C has a spectacular aura about
Default

Quote:
Originally Posted by R2RG View Post
WOW !
now i have got you !
The NSLog itself takes too much time !

i was thinking that you talked about the time it takes to write from the usb cable of the iphone , to the computer !! ( i am electrical engineer )

so you say that nslog command takes time when debugging with the iphone, and also when only simulation ? .... mmmm...

thanks a lot guys !!

if i wasnt here, i couldnt mention this for ever !!

this is the second time you really help me...
AND save my job !

thanks a lot for answer my stupid questions... !
Woo hoo! Finally he gets it! We've been trying to get you to understand that for a long time. You had a mental block it seems.

Take a look at the code I posted when I first joined this thread. I showed how to calculate time intervals without creating any NSDate objects at all:


Code:
NSTimeInterval 
  startTime, 
  firstElapsedTime;

startTime = [NSDate timeIntervalSinceReferenceDate];
//do stuff that we want to time.
firstElapsedTime = [NSDate timeIntervalSinceReferenceDate] - startTime;
That code uses an NSDate class method that returns an NSTimeInterval (which is a double, not an object)

BTW, sending data to a log IS slower on a device because, as you say, it has to format the information as packets and send them over USB. The simulator is also somewhat slower than native Mac code. Nevertheless, the NSLog statement is really slow even in native Mac OS, with no data communications or simulated platforms.
__________________
Regards,

Duncan C
WareTo

Check out our apps in the Apple App store


Check out this password generator app that shows various techniques including using a data container singleton object to share data between objects in your project.

See this tutorial on using UIView animations and layer animations:

See this thread on generating random, non-repeating text

Check out a very cool Macintosh Kaleidoscopes app called ScopeWorks that we released to the Mac App store.
Duncan C is offline   Reply With Quote
Reply

Bookmarks

Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off
Trackbacks are On
Pingbacks are On
Refbacks are On



» Advertisements
» Online Users: 344
6 members and 338 guests
doffing81, dre, iOS.Lover, jenniead38, Kirkout, Wikiboo
Most users ever online was 1,387, 04-10-2012 at 04:21 AM.
» Stats
Members: 175,663
Threads: 94,120
Posts: 402,898
Top Poster: BrianSlick (7,990)
Welcome to our newest member, LezB44
Powered by vBadvanced CMPS v3.1.0

All times are GMT -5. The time now is 02:11 AM.
Powered by vBulletin® Version 3.8.0
Copyright ©2000 - 2012, Jelsoft Enterprises Ltd.
Search Engine Friendly URLs by vBSEO 3.3.0