crashes when set_zoom() is called via a PTP script

adeuring

26

« on: 08 / January / 2013, 16:59:33 »

Advertisements

Hello,

I tried the following script on an SX30 (firmware version 1.00P, CHDK version sx30-100p-1.1.0-2327-full:

Code: [Select]

enter_alt()
if not get_mode() then
    switch_mode_usb(1)
    while get_mode() ~= true do
        sleep(100)
    end
end
set_zoom_speed(100)
set_zoom(60) -- value does not matter.
return get_zoom()

If I remove the enter_alt() call, the camera crashes when this script is called for 20 or 30 times.

I called this via my Python PTP/CHDK library:

Code: [Select]

from ptp import PTPDevice, CHDKScriptStatus
import sys
from time import sleep

d = PTPDevice()
id = d.chdkExecLua("""
    enter_alt()
    if not get_mode() then
        switch_mode_usb(1)
        while get_mode() ~= true do
            sleep(100)
        end
    end
    set_zoom_speed(100)
    set_zoom(%i)
    return get_zoom()
""" % int(sys.argv[1]))

while d.chdkScriptStatus(id) & CHDKScriptStatus.MSG == 0:
    sleep(0.050)
print d.chdkReadScriptMessage()

Of course it's not a problem to call enter_alt() but, well, at least a heads up for others

ALso, I am a bit curious why the alt mode makes such a difference.

Logged

reyalp

14118

Re: crashes when set_zoom() is called via a PTP script

« Reply #1 on: 09 / January / 2013, 03:29:43 »

That's quite strange that enter_alt should matter. How sure are you this is actually a determining factor, rather than random coincidence?

If you get a romlog http://chdk.wikia.com/wiki/Debugging#Camera_crash_logs_.28romlog.29 that may shed some light on what is crashing.

Have you tried putting an additional delay between the switch_mode_usb() and the set_zoom()? I wouldn't be totally surprised if get_mode could change before everything was completely done.

Logged

Don't forget what the H stands for.

adeuring

26

Re: crashes when set_zoom() is called via a PTP script

« Reply #2 on: 09 / January / 2013, 13:18:56 »

Quote from: reyalp on 09 / January / 2013, 03:29:43

That's quite strange that enter_alt should matter. How sure are you this is actually a determining factor, rather than random coincidence?

Let's say that crashes are much less likely when enter_alt() is called. I just ran this script, to get some numbers/data:

Code: [Select]

import setup_path
from ptp import PTPDevice, CHDKScriptStatus
import sys
from time import sleep

def zoom(d, v):
    id = d.chdkExecLua("""
        --enter_alt()
        if not get_mode() then
            switch_mode_usb(1)
            while get_mode() ~= true do
                sleep(100)
            end
        end
        set_zoom_speed(100)
        set_zoom(%i)
        return get_zoom()
    """ % v)

    while d.chdkScriptStatus(id) & CHDKScriptStatus.MSG == 0:
        sleep(0.050)
    print d.chdkReadScriptMessage()


d = PTPDevice()

z1 = int(sys.argv[1])
z2 = int(sys.argv[2])

count = 0
run = True
while run:
    count += 1
    try:
        zoom(d, z1)
        zoom(d, z2)
    except Exception, e:
        print "error", type(e), e
        print "loops", count
        run = False

Nearly the same as the one I useded yesterday; the difference iss that the same PTP connection is now used.
The first run stopped with a camera crash in the 23rd loop. PTP error was 0x02fd, I believe that just indicated that the device "disappeared". See romlog-1.log.

The second run lasted 24 loops; the Python script again reported PTP error 0x02fd. See romlog-2.log

The third run crashed in the 23rd loop, PTP error 0x02fd.

For a fourth run, I added a sleep call before set_zoom_speed():

Code: [Select]

        --enter_alt()
        if not get_mode() then
            switch_mode_usb(1)
            while get_mode() ~= true do
                sleep(100)
            end
        end
        sleep(1000)
        set_zoom_speed(100)
        set_zoom(%i)
        return get_zoom()

A fifth run, now with enter_alt enabled, went fine for 127 loop. I then hit ctrl-C:

Code: [Select]

        enter_alt()
        if not get_mode() then
            switch_mode_usb(1)
            while get_mode() ~= true do
                sleep(100)
            end
        end
        set_zoom_speed(100)
        set_zoom(%i)
        return get_zoom()

Quote from: reyalp on 09 / January / 2013, 03:29:43

If you get a romlog http://chdk.wikia.com/wiki/Debugging#Camera_crash_logs_.28romlog.29 that may shed some light on what is crashing.

Two logs attached; those from runs 3 and 4 will follow in another message.

Have you tried putting an additional delay between the switch_mode_usb() and the set_zoom()? I wouldn't be totally surprised if get_mode could change before everything was completely done.

Yes, I tried an additional delay, but it didn't help.

And yes, I know, all this sounds a bit weird ... and of course I can't rule out any bugs in my Python library...

romlog-1.log (3.38 kB - downloaded 45 times.)

romlog-2.log (3.25 kB - downloaded 44 times.)

Logged

adeuring

26

Re: crashes when set_zoom() is called via a PTP script

« Reply #3 on: 09 / January / 2013, 13:21:30 »

now the logs from the test runs 3 and 4

romlog-3.log (3.01 kB - downloaded 42 times.)

romlog-4.log (3.89 kB - downloaded 41 times.)

Logged

reyalp

14118

Re: crashes when set_zoom() is called via a PTP script

« Reply #4 on: 09 / January / 2013, 16:49:50 »

Quote from: adeuring on 09 / January / 2013, 13:18:56

And yes, I know, all this sounds a bit weird ... and of course I can't rule out any bugs in my Python library...

The only bug I could see causing this kind of behavior is if you try to start a script while one is already running.

The romlogs seem to be spread over several different tasks and files. Nothing immediately familiar to me. All except for the first one seem zoom related though, which suggests that's not just random memory corruption or something like that. Also the camera log portion always ends with SS:OptAt=... which is probably referring to optical zoom position.

Logged

Don't forget what the H stands for.

adeuring

26

Re: crashes when set_zoom() is called via a PTP script

« Reply #5 on: 09 / January / 2013, 17:59:29 »

Quote

The only bug I could see causing this kind of behavior is if you try to start a script while one is already running.

OK, I tried again with a few additional checks:

Code: [Select]

import setup_path
from ptp import PTPDevice, CHDKScriptStatus, CHDKMessageType
import sys
from time import sleep

def zoom(d, v):
    id = d.chdkExecLua("""
        --enter_alt()
        if not get_mode() then
            switch_mode_usb(1)
            while get_mode() ~= true do
                sleep(100)
            end
        end
        set_zoom_speed(100)
        set_zoom(%i)
        return get_zoom()
    """ % v)
    assert d.chdkScriptStatus(id) & CHDKScriptStatus.RUN == 1

    while d.chdkScriptStatus(id) & CHDKScriptStatus.MSG == 0:
        sleep(0.050)
    val, type_, res_id = d.chdkReadScriptMessage()
    print val, type_, res_id
    assert d.chdkScriptStatus(id) & CHDKScriptStatus.RUN == 0
    assert res_id == id
    assert type_ == CHDKMessageType.RET


d = PTPDevice()

z1 = int(sys.argv[1])
z2 = int(sys.argv[2])

count = 0
while True:
    count += 1
    try:
        zoom(d, z1)
        zoom(d, z2)
    except Exception, e:
        print "loops", count
        raise

Same as before: The camera crashes (ptp.PTPError: (765, 'unexpected return code 0x2fd')), once it happened already in the 11th loop run. Assuming i didn't mess up completely with constant definitions and mapping the data retruned by read_script_message() to Python objects, I am pretty confident that this is the only script that was running.

But I'll try this with chdkptp tomorrow, just to be sure. (Too late for me to try this right now

Logged

reyalp

14118

Re: crashes when set_zoom() is called via a PTP script

« Reply #6 on: 09 / January / 2013, 21:56:28 »

Quote from: adeuring on 09 / January / 2013, 17:59:29

Same as before: The camera crashes (ptp.PTPError: (765, 'unexpected return code 0x2fd')), once it happened already in the 11th loop run.

This is PTP_ERROR_RESP_EXPECTED in the ptpcam code (not an actual USB error). This appears exactly once, in ptp_usb_getresp. I expect that just means the camera crashed, although in my experience PTP_ERROR_IO is more common when the camera crashes. May depend on the host OS.

Quote

Assuming i didn't mess up completely with constant definitions and mapping the data retruned by read_script_message() to Python objects, I am pretty confident that this is the only script that was running.

Based on the romlogs, I'd say that was a long shot start. I'd expect kbd task or possibly the ptp task to crash in that case, while your romlogs seem to point to Canon zoom related code.

I'll try to reproduce it on my cameras when I get some time.

Nice job with the python interface btw, feel free to add information about it to the wiki if you want. Suggestions and improvements for the ptpcam based code and API are also welcome.

edit:
It might be worth trying to reproduce it as a standalone script on the camera, without any PTP at all.

Logged

Don't forget what the H stands for.

adeuring

26

Re: crashes when set_zoom() is called via a PTP script

« Reply #7 on: 10 / January / 2013, 16:32:16 »

Quote from: reyalp on 09 / January / 2013, 21:56:28

Quote from: adeuring on 09 / January / 2013, 17:59:29
Same as before: The camera crashes (ptp.PTPError: (765, 'unexpected return code 0x2fd')), once it happened already in the 11th loop run.
This is PTP_ERROR_RESP_EXPECTED in the ptpcam code (not an actual USB error). This appears exactly once, in ptp_usb_getresp. I expect that just means the camera crashed, although in my experience PTP_ERROR_IO is more common when the camera crashes. May depend on the host OS.

Yes, as I understand it, libptp return 0x2fd when the USB device is gone, i.e., when for example the camera poweres off. I saw it also when the camera crashed for other reasons.

Quote

Quote
Assuming i didn't mess up completely with constant definitions and mapping the data retruned by read_script_message() to Python objects, I am pretty confident that this is the only script that was running.
Based on the romlogs, I'd say that was a long shot start. I'd expect kbd task or possibly the ptp task to crash in that case, while your romlogs seem to point to Canon zoom related code.

I'll try to reproduce it on my cameras when I get some time.

I tried it now with a script on the SD card:

Code: [Select]

set_zoom_speed(100)
exit_alt()
count = 0

while count < 100 do
    print(count)
    set_zoom(60)
    sleep(500)
    set_zoom(1)
    sleep(500)
    count = count + 1
end

I ran the script three times; it crashed in the first run and in the third run (see the attached rom logs) after about 20 loop iterations; the second run stopped with the message "ERROR: NULL error message - press shutter to close" in the 8th iteration.

Next, I commented "exit_alt()" out and ran the script again for three times. It succeded two times; the other run was aborted with "ERROR: NULL error message - press shutter to close" after 73 iterations.

Quote

Nice job with the python interface btw, feel free to add information about it to the wiki if you want. Suggestions and improvements for the ptpcam based code and API are also welcome.

thanks

I am a bit busy during the next weeks but will for sure remember to add some documentation in the wiki. (Another reason to defer this is that I'm working on a slightly higher level interface but did not get very far yet; see the launchpad code page.) As for suggestions/improvements, I did not make many changes to the libptp extensions from ptpcam/chdkptp. The main change is my approach to use a mostly unmodified version of Mariusz Wołoszyn original PTP library, in order to get advantage of the automake/autoconf magic.

Other than that, I'd only claim that my variant of the YUV->RGB conversion of live images is slightly faster than that from chdkptp: repeatedly required calculations like y << 12 or u * some_constant_value are done just once. That saved 20% or 25% runtime of a total conversion time of ... ummm... I can't remember... a few msec, I guess, on an i7 laptop, so, not really important. But it might perhaps be more noticeable when used on a Raspberry.

Anyway, if there is interest, I can try to submit patches.

romlog-standalone-1.log (3.5 kB - downloaded 42 times.)

romlog-standalone-2.log (4.26 kB - downloaded 42 times.)

Logged