CHDKPTP - PC Remote Control Performance Analysis - page 26 - RAW Shooting and Processing - CHDK Forum

CHDKPTP - PC Remote Control Performance Analysis

  • 465 Replies
  • 119820 Views
*

Offline reyalp

  • ******
  • 14080
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #250 on: 21 / September / 2012, 00:20:52 »
Advertisements
When you say X bytes/shot what are you taking as your initial value ? I would suggest taking at least one shot first since it would be unsurprising if some resources don't get allocated until the first shot.

Code: [Select]
> =return get_meminfo().free_size
10:return:380008
> =shoot()
> =return get_meminfo().free_size
12:return:379904
> =shoot()
> =return get_meminfo().free_size
14:return:379904
Note, I'm not saying the initial drop explains everything, just suggesting that taking it out might make a pattern more apparent if you count the initial drop separately.

The thing we need to do is narrow down which step(s) trigger the leak.

~30-40 bytes/file as you see with shoot only would be within previous experience. It's possible it doesn't go up after every shot because the Canon firmware allocates in some structure in chunks, e.g. it uses 24 bytes per file, but allocates enough for 10 files, uses that, repeat.

Losing more when files / directories are deleted is odd. OTOH, it would be unexpected by the Canon firmware.

If it's a CHDK leak, then it's hard to see how it would happen without each time an instance of a the leaking command is called. E.g. if there is a memory leak in something called by 'rm' then you should lose some memory each time you call it.

Quote
All tests show a screen shot at 1 shoot and 100 shoots.   Some tests have screen shots at 22, 33 and 51 shoots added, so you can observe leak progression.
Screenshots really aren't every effective way of logging this kind of information. If you use printf instead of print, it goes to the gui console and you can select and copy with ctrl+ins (nothing will appear until the sequence is finished). Better still, you could log to a file. You also don't have to print out the entire meminfo, just get_meminfo().free_size should be fine, and a lot easier to follow.

With a proper log we could see if it drops X bytes every N shots or something like that.

Ok, while I was composing this post, I ran
Code: [Select]
for i=1,50 do
 local l,r=con:execwait('shoot();return get_meminfo().free_size')
 sys.sleep(500)
 printf("r:%s\n",r)
end
on my D10. The results are interesting: The first 39 shots all return exactly the same value. The subsequent shots seem to consume between 24 and 72 bytes/shot, without any obvious pattern (?!). I had taken some shots (about 10 ?) manually before starting this sequence.

I took another 50 shot series and got the same decline immediately.

It's very hard for me to think of a way this pattern would be caused by CHDK.
Don't forget what the H stands for.

*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #251 on: 21 / September / 2012, 09:06:33 »
Quote "When you say X bytes/shot what are you taking as your initial value ? I would suggest taking at least one shot first since it would be unsurprising if some resources don't get allocated until the first shot."

Yes I checked this carefully.  I have 4 sniffs per shoot, at the entry to dcimdl and one after each internal call.  The initial variations I see with first few shoots are within a couple hundred bytes of the very first value, more or less as you demonstrate.  Even after several shoots the free mem can return to its original value.  For example, look at the difference between 70a (initial conditions) and 70b in the ZIP, which is 22 shots later: the free mem pattern, +/- a couple hundred bytes, is essentially the same.  So you really need to acquire many more than 20 shots before you can start measuring the drop.  After that, free mem seems to decline more smoothly.  Hence I can take any free mem value up to 20 shoots as the initial value.  Overall, the value at 100 shoots -vs- any value up to 20 shoots will give the same result +/- a few percent.

Quote "it uses 24 bytes per file, but allocates enough for 10 files, uses that, repeat."

Sensible and I agree.

Quote "Losing more when files / directories are deleted is odd. OTOH, it would be unexpected by the Canon firmware"

Yes that is what I wanted show you here.  Did you mean "expected?"  I did *attempt* a convoluted test to determine that but it was unsuccessful ... in essence, while connected to CHDKPTP, sniff, use camera shoot button, sniff ... but doing it ran a script instead (message flash in LL corner) and did not shoot.

Quote "If it's a CHDK leak, then it's hard to see how it would happen without each time an instance of a the leaking command is called. E.g. if there is a memory leak in something called by 'rm' then you should lose some memory each time you call it."

I've tried to give some thought about these scenarios too, but, I don't know the mechanisms so my contribution is very limited.

Quote "If you use printf instead of print"

I see, I will modify my code so it does both and send you a text file of the console.

Quote "The results are interesting: The first 39 shots all return exactly the same value. The subsequent shots seem to consume between 24 and 72 bytes/shot, without any obvious pattern (?!). I had taken some shots (about 10 ?) manually before starting this sequence."

Yes, that's "good," what I reported and what you see are consistent.  The equation I used to obtain the previous results is:

     X bytes/shoot = ( freemem{shoot 1} - freemem{shoot 100} )  /  100

I think my results are reliable, standardized on 100 shoots. 

It is worthwhile to note that going long, say to 500 shoots, the X bytes/shoot is slightly nonlinear.  For example, running TEST 6 JPG&CR2 at 100 starts out at 200 bytes, then goes to 219, 223, and 226, part way through settling on 226 after 500 shoots.  One obvious explanation is fragmentation.

Quote "I took another 50 shot series and got the same decline immediately."

Those are the kids of things I see too  ... if you don't reboot, then you can preserve the cumulative degradation, vary the test sequence, etc.  I've done this several times.  That's why in my test sequence the reboots are important for consistent results.

Quote "It's very hard for me to think of a way this pattern would be caused by CHDK."

What about this? ... it's is a guess based on pure imagination ... when Canon writes out the file it allocates memory resources and then when a dcimdl command (which may not necessarily malloc() anything) does its thing, those resources aren't deallocated.  In a sense CHDK does not know what Canon allocated hence it does not know what to free ??  I wanted to test|determine if Canon frees resources with with its *own* write/delete file, but it seems I can't get Canon to work while the camera is connected to CHDKPTP so I can't operate the camera and sniff memory "manually."  If you know of a way to do it, I'll give it a shot.

==>> NEW.  Here's something I've seen happen twice on the USB 2.0 computer.  In all my tests I have liveview enabled.  The event appears random and I am sure this one is not memory related, because this last one happened at ~18 shoots.  The link becomes disconnected with "ERROR download failed."  The CR2 file is partially transferred, but camera does not crash, Fig 1.  That is, without rebooting I can reconnect CHDKPTP, restart the shoot loop, and the old CR2 will be transferred correctly, Fig 2.  What could this be?

*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #252 on: 21 / September / 2012, 16:01:53 »
SIDETRACK --  3rd ERROR download, ptp disconnection... I am pretty sure this is not CHDKPTP, but maybe you've seen it before.  I have not noticed this on the USB 1 WinXP box (~2 weeks work).  I tried another USB 2.0 port on this Vista box (back instead of front) and am having trouble getting past this one.  Maybe it could be relevant to the following.

Here's what happens ...

 a) CPU is near 0% with camera OFF and CHDKPTP closed // OK.   
 b) When I PUP and start CHDKPTP, CPU is still near 0% // OK. 
 c) The moment I press Rec that's when a new scvhost pops up and puts the CPU to 100%.
 d) As long as CHDKPTP is running, CPU stays at 100%
 e) If close and PDN camera, that svchost hangs around until I kill it.

Even though the system keeps running apparently fine, I think this could be related to the download error.  If you have any idea that could help get me past this block, it would be sincerely appreciated.

*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #253 on: 21 / September / 2012, 17:09:51 »
Found the 100% CPU problem // I'd like to put few good choice words in front of "Vista" but alas this forum does not allow swearing.  If you don't have this yet, get Microsoft's Sysinternals Process Explorer (procexp.exe) // it's a crazy good tool.  You can set it to replace Task Manager on Ctrl-Alt-Del.  Right click on offending hog svchost -> Properties -> Services.  There you should find "Offline files," and stop the service.
« Last Edit: 21 / September / 2012, 17:25:47 by SticK »


*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #254 on: 21 / September / 2012, 23:40:00 »
S90_100C First two consistent long results 500 shoot+dcimdl with USB 2.0.

After 2x500 successful runs, chances are high that the svchost hog caused interference with downloads.  One event I noted was after having fixed the hog (in the middle of the 2nd 500 test of 3) at shoots=304 when I interacted with the computer (file saves across network) it got the same ERROR download (but no hog).  I am a bit concerned there // hope it's isolated but will keep an eye out.  Now if I want no spurious interaction errors during the test I have to keep my hands off the bench computer.

JPG & CanonCR2

CONSOLE TXT #77: The original dcimdl that deletes the subdirs in DCIM and keeps DCIM
Result: 284 B/shoot

CONSOLE TXT #79: The original dcimdl that deletes files only keeping DCIM and both subdirs
Result: 224 B/shoot

Consistent trend with TEST #2 and TEST #3: deleting subdirs increases leak, although the ratio is not as high in the long test here.  Your thoughts about patterns and where the leaks could be coming from?  What could you do?  What can I do next?

*

Offline reyalp

  • ******
  • 14080
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #255 on: 22 / September / 2012, 00:05:16 »
Quote "Losing more when files / directories are deleted is odd. OTOH, it would be unexpected by the Canon firmware"

Yes that is what I wanted show you here.  Did you mean "expected?"
No, I mean files / directories disappearing out from under the Canon firmware is not expected by the firmwares authors, so odd behavior should not entirely surprising.

Quote
For example, running TEST 6 JPG&CR2 at 100 starts out at 200 bytes, then goes to 219, 223, and 226, part way through settling on 226 after 500 shoots.  One obvious explanation is fragmentation.
The get_meminfo values should not vary depending on fragmentation. On cameras using firmware functions for this (as the S90 builds are) it has separate totals for free size and largest free block.
Quote
Quote "It's very hard for me to think of a way this pattern would be caused by CHDK."

What about this? ... it's is a guess based on pure imagination ... when Canon writes out the file it allocates memory resources and then when a dcimdl command (which may not necessarily malloc() anything) does its thing, those resources aren't deallocated.
My test was without any dcimdl at all, just shoot and get free memory.

Quote
In a sense CHDK does not know what Canon allocated hence it does not know what to free ??  I wanted to test|determine if Canon frees resources with with its *own* write/delete file, but it seems I can't get Canon to work while the camera is connected to CHDKPTP so I can't operate the camera and sniff memory "manually."
Have you tried sending the unlock levent I've mentioned numerous times previously ?  =post_levent_to_ui(4484)

I don't know why you have trouble with this, but you could unplug the camera, do some stuff with the canon menu and plug it back in. Note that it will switch to playback mode when you plug in, which may influence memory usage. You could also write a standalone lua script to report memory usage on screen.

Operating the canon menu remotely should also be valid. I'm pretty confident that just running a simple lua function like click('key') doesn't leak. To verify this, I just ran the following script and all the returned values were identical
Code: [Select]
!r={}; for i=1,1000 do local s,m=con:execwait("click('set'); sleep(10); return get_meminfo().free_size"); r[i]=m ; end

Quote
The event appears random and I am sure this one is not memory related, because this last one happened at ~18 shoots.  The link becomes disconnected with "ERROR download failed."  The CR2 file is partially transferred, but camera does not crash, Fig 1.  That is, without rebooting I can reconnect CHDKPTP, restart the shoot loop, and the old CR2 will be transferred correctly, Fig 2.  What could this be?
I have no idea, there's no specific information in your screenshots and I don't recall seeing anything like this. FWIW, live view doesn't update when a cli command is running, so that shouldn't be an issue. If some other software running on the system tries to access the camera that could interrupt the download. Perhaps it could also be flaky USB hardware.

Quote
deleting subdirs increases leak, although the ratio is not as high in the long test here. Your thoughts about patterns and where the leaks could be coming from?
If the canon firmware "leaked" a very small amount of memory each time a DCIM sub directory was created, this would be no problem whatsoever in any scenario the designers would worry about.

It occurs to me that in-memory representation of the directory structure could explain both the per shot memory use and the extra cost from deleting. If it stores a representation of the directory table and doesn't re-use the "deleted" entries immediately, that would fit pretty well.
Quote
What could you do?
Reboot before it gets too low, and don't delete unnecessarily.
Don't forget what the H stands for.

*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #256 on: 22 / September / 2012, 01:41:15 »
Quote "Have you tried sending the unlock levent I've mentioned numerous times previously ?  =post_levent_to_ui(4484) "

Yes I have tried it a few times and the only buttons that work are camera PLAY and Alt, whether I send the event or not.  Pressing camera SHOOT runs a script (flash in lower left corner) but does nothing else.

Quote "you could unplug the camera, do some stuff with the canon menu and plug it back in"

If I unplug which I tried too, there's no change in behavior from the above without rebooting.

Quote "Operating the canon menu remotely should also be valid."  "I'm pretty confident that just running a simple lua function like click('key') doesn't leak."

This would work ... but that's my question ... for example SET might not leak, but just to be sure ... when I press SHOOT on the CHDKPTP GUI, does you invoke malloc anywhere along the before calling the Canon shoot function if that's the way it works ?

Quote "It occurs to me that in-memory representation of the directory structure could explain both the per shot memory use and the extra cost from deleting. If it stores a representation of the directory table and doesn't re-use the "deleted" entries immediately, that would fit pretty well."

That's what I was trying to determine, and given your confirmation of my last question above I can get some results.

Quote "live view doesn't update when a cli command is running, so that shouldn't be an issue"

That's good.

My quote "What could you do? "
Quote "Reboot before it gets too low, and don't delete unnecessarily."

I know this and if I could afford rebooting I would not ask  // I expected a technological solution idea we work out together somehow.  Maybe it's not possible.  In this context, you haven't yet addressed my last comment&question:

  "What about this? ... it's is a guess based on pure imagination ... when Canon writes out
  the file it allocates memory resources and then when a dcimdl command (which may not
  necessarily malloc() anything) does its thing, those resources aren't deallocated.  In a
  sense CHDK does not know what Canon allocated hence it does not know what to free ?? "

Could you talk about this please?

*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #257 on: 22 / September / 2012, 09:57:46 »
S90_100c  2000xJPG  shoot+dcimdl

CONSOLE TXT #80: The original dcimdl that deletes the JPG file only after transfer to PC keeping DCIM and both subdirs.
Result: 112 B/shoot

Conclusion: This is similar to #79, but with one file instead of two.  TEST #79 resulted in 224 B/shoot, so we have exactly 1/2 the leak.  Hence by using "keep all directories after file delete" mode of dcimdl, memory loss occurs at a rate of 112 bytes per file, and, running to 500 shoots is enough to determine leak accurately.

Now that we have a more quantitative understanding of the behavior we can get a better handle ...

Next ...... try to simulate this test manually with Canon only to determine if leak behavior is different.


*

Offline SticK

  • *****
  • 779
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #258 on: 22 / September / 2012, 11:38:05 »
OOPS! ... CANON MENU TRAP // #81 //-- Can you please read my comments in the console file.

How can I past this so we can get the test results?

*

Offline reyalp

  • ******
  • 14080
Re: CHDKPTP - PC Remote Control Performance Analysis
« Reply #259 on: 22 / September / 2012, 16:16:16 »
My quote "What could you do? "
Quote "Reboot before it gets too low, and don't delete unnecessarily."

I know this and if I could afford rebooting I would not ask  // I expected a technological solution idea we work out together somehow.
1)  Please read the second part of this post again: http://chdk.setepontos.com/index.php?topic=8613.msg91040#msg91040
If you can't afford to reboot the camera every 1000 images, and aren't prepared to do a hard reset when it crashes, then CHDK may not be a suitable solution for your application.
2) Assuming this "leak" is actually normal firmware behavior (which appears likely at this point), there's really very little alternative. It's unlikely it can be prevented with any reasonable amount of effort.
3) The most plausible approach would seem to be suppressing the file creation step completely, and downloading the data over USB. This might be possible, but would likely require substantial reverse engineering effort. Although I haven't tested yet, I expect srsa's remote capture system will not prevent this "leak", since it gets the data in the file write task, and still creates "ghost" files in the Canon UI.
4) You could delay the inevitable by loading CHDK in exmem (freeing up an additional 300k+ for the Canon firmware to malloc from), but it looks like the necessary parameters have not be determined for this camera yet.
Quote
  "What about this? ... it's is a guess based on pure imagination ... when Canon writes out
  the file it allocates memory resources and then when a dcimdl command (which may not
  necessarily malloc() anything) does its thing, those resources aren't deallocated.  In a
  sense CHDK does not know what Canon allocated hence it does not know what to free ?? "

Could you talk about this please?
It just meaningless speculation that has no relation to how anything actually works. Also, the "leak" appears without dcimdl. If you want to investigate the possibility that some of the commands in dcimdl produce additional leaks, then as I've suggested several times before, you should try those commands in isolation.
« Last Edit: 22 / September / 2012, 20:19:37 by reyalp »
Don't forget what the H stands for.

 

Related Topics