chdkptp & IXUS160 - strange usbfs error - General Help and Assistance on using CHDK stable releases - CHDK Forum

chdkptp & IXUS160 - strange usbfs error

  • 8 Replies
  • 4208 Views
*

Offline axman

  • ***
  • 145
chdkptp & IXUS160 - strange usbfs error
« on: 24 / January / 2016, 11:57:00 »
Advertisements
Hi all,

Using chdkptp build 694 pulled from assembla.com/svn/chdkptp/trunk, running it on Ubuntu 15.10 x86_64.  I have a script giving chdkptp commands every n minutes.  Script works 100% correctly about 95% of the time..    Failure symptom at most basic level is, chdkptp cannot connect to the IXUS160.  It sees no devices on the USB bus.  Occasionally, I see this error in /var/log/syslog at same time my script fails (eg chdkptp fails to connect to the camera)

Code: [Select]
Jan 24 06:45:08 zeus kernel: [721933.564704] usb 1-2: usbfs: interface 0 claimed by usbfs while 'chdkptp' sets config #1
Jan 24 06:45:08 zeus kernel: [721933.564731] usb 1-2: usbfs: process 21919 (chdkptp) did not claim interface 0 before use
Jan 24 06:45:08 zeus kernel: [721933.730040] usb 1-2: reset high-speed USB device number 99 using xhci_hcd
Jan 24 06:45:18 zeus kernel: [721944.331886] usb 1-2: USB disconnect, device number 99

Script runs in an infinite loop - for days on end.  The errors occur seemingly at random, but statistically they happen about 3-5% of the time..  Since I have >95% success, I don't think I'm doing something wrong in my script code, but it's possible.. 

Confirm that I do have the udev rule in place which prevents libGphoto from grabbing the cam..  I did not see the cam's signature in /lib/udev/hwdb.d/20-libgphoto2-6.hwdb, but I could have missed it..

Any comments or suggestions of something to poke at would be most welcome.

*

Offline srsa_4c

  • ******
  • 4451
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #1 on: 24 / January / 2016, 12:34:16 »
I don't really have an idea what could be going on. Some search results mention problems with USB 3 - is the port you're using USB 2.0 or 3?

*

Offline reyalp

  • ******
  • 14080
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #2 on: 24 / January / 2016, 15:13:38 »
Hi all,

Using chdkptp build 694 pulled from assembla.com/svn/chdkptp/trunk, running it on Ubuntu 15.10 x86_64.  I have a script giving chdkptp commands every n minutes.  Script works 100% correctly about 95% of the time..    Failure symptom at most basic level is, chdkptp cannot connect to the IXUS160.  It sees no devices on the USB bus.  Occasionally, I see this error in /var/log/syslog at same time my script fails (eg chdkptp fails to connect to the camera)
Can you give a bit more information about how the script works? Do you have an external process (shell script, cron job etc) launching chdkptp for each command?

How much time is there between commands? If you try to connect very soon after disconnecting, you may run into trouble.

What state is the camera in after the script fails? Is the the camera still on, or has it crashed? If it's on, can you interact with it using the physical keyboard?

Quote
Code: [Select]
Jan 24 06:45:08 zeus kernel: [721933.564704] usb 1-2: usbfs: interface 0 claimed by usbfs while 'chdkptp' sets config #1
Jan 24 06:45:08 zeus kernel: [721933.564731] usb 1-2: usbfs: process 21919 (chdkptp) did not claim interface 0 before use
Jan 24 06:45:08 zeus kernel: [721933.730040] usb 1-2: reset high-speed USB device number 99 using xhci_hcd
Jan 24 06:45:18 zeus kernel: [721944.331886] usb 1-2: USB disconnect, device number 99
When it fails like, is the number always 99?

One thing that comes to mind is that the chdkptp code does a USB reset on disconnect. This is something I blindly copied from the the original ptpcam code.

Quote
Confirm that I do have the udev rule in place which prevents libGphoto from grabbing the cam..  I did not see the cam's signature in /lib/udev/hwdb.d/20-libgphoto2-6.hwdb, but I could have missed it..
I would expect this to be an all or nothing thing, if you are able to connect at all, the udev entries should be correct. I guess there could be some other periodic task on the system that somehow triggers access to the USB stuff, but IMO this is unlikely.
Don't forget what the H stands for.

*

Offline axman

  • ***
  • 145
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #3 on: 26 / January / 2016, 17:48:07 »
Hello, thanks for the feedback.

I don't really have an idea what could be going on. Some search results mention problems with USB 3 - is the port you're using USB 2.0 or 3?
It is USB 3.0 - Intel NUC 54250WYK http://www.intel.com/content/www/us/en/nuc/nuc-kit-d54250wyk.html
BIOS is within one version of most recent.
Can you give a bit more information about how the script works? Do you have an external process (shell script, cron job etc) launching chdkptp for each command?

How much time is there between commands? If you try to connect very soon after disconnecting, you may run into trouble.

What state is the camera in after the script fails? Is the the camera still on, or has it crashed? If it's on, can you interact with it using the physical keyboard?

Script is a wrapper to execute chdkptp commands.  (2) cameras are connected via USB bus; cameras have a shorted ON/OFF switch; powered on via wrapper script -> who calls an arduino application to close a relay.

Chdkptp is run " -i " inside a gnu 'screen' session.  Chdkptp operational commands are fed into the screen-session.  Wrapper script sleeps between 3-5 seconds between chdkptp commands - to give the camera a chance to respond.  Example of wrapper script executing chdkptp command below;  I do not yet pass the camera serial number as a variable (it's on the list.)  Each camera runs its own wrapper; they run at 3 minute and 5 minute cycles, respectively; they collide at the 00, 15, 30 & 45 minute marks.  I've got basic lockfile management in place, such that one cam defers processing if another cam is found active on the usb bus.

Code: [Select]
/usr/bin/screen -p 0 -S remoteshoot-c -X stuff "!status,msg=cli:execute'connect -b=001 -p=0x32aa -s=5B362D50A2E345DB8EE3558CFD0A7030' if msg then print(msg) end if not status then os.exit(1) end$CRLF"
ERRLVL1="$?"

#echo "$(timestamp) canon_job: exec chdkptp connect via lua, errlvl $ERRLVL1"
if [[ "$ERRLVL1" -ne "0" ]]; then
exit 1
fi
sleep 4
Camera state after a failure is ON and in Play mode (eg View last image taken in LCD).  Wrapper script notices the errorlevel and powers camera off, usually leaving lens extended.

Could I interact with it after a crash?  Yes, immediately after I can make a screen session with chdkptp inside, and send the exact same commands that fail - and >99% of the time it will succeed..  But reconnecting after a failure is subtly different than the original failure case.  It is a "new" (fresh) usb connection to the device..

I can easily sleep more between chdkptp commands, the time sensitivity for the wrapper is on the order of minutes..  I can also make some logic that detects when the initial connect attempt fails, then make it drop back and try again..

Quote
Code: [Select]
Jan 24 06:45:08 zeus kernel: [721933.564704] usb 1-2: usbfs: interface 0 claimed by usbfs while 'chdkptp' sets config #1
Jan 24 06:45:08 zeus kernel: [721933.564731] usb 1-2: usbfs: process 21919 (chdkptp) did not claim interface 0 before use
Jan 24 06:45:08 zeus kernel: [721933.730040] usb 1-2: reset high-speed USB device number 99 using xhci_hcd
Jan 24 06:45:18 zeus kernel: [721944.331886] usb 1-2: USB disconnect, device number 99

Quote
When it fails like, is the number always 99?

One thing that comes to mind is that the chdkptp code does a USB reset on disconnect. This is something I blindly copied from the the original ptpcam code.

Re: the dev id number 99;  No, that number increments once each time the usb device is seen by the host PC.  After a few hundred iterations and no NUC reboot, the number is, well, a few hundred, I guess.

It may be that the chdkptp usb-reset you mentioned is what's biting me..

I could expose if it's that by adapting multicam to my wrapper.. 

I played a little with multicam, but got hung up on making it exec 'remoteshoot' - which is quite handy for me.  I *could* simply have my wrapper let multicam save to SDcard, then go get images from SDcard instead of remoteshoot, but it was more code..   gotta not be lazy..

I'll try multicam and see if the error persists.

Thanks for the comments, any others are much appreciated.

modification to clarify script operation, cycling and collisions on usb bus.
« Last Edit: 26 / January / 2016, 18:00:22 by axman »


*

Offline srsa_4c

  • ******
  • 4451
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #4 on: 26 / January / 2016, 18:20:50 »
It is USB 3.0 - Intel NUC 54250WYK http://www.intel.com/content/www/us/en/nuc/nuc-kit-d54250wyk.html
If the issue is due to the kernel driver, one thing you could try is to connect the cam to one of the USB 2.0 ports (the intel spec sheet mentions 2 of them, inside, as headers).

*

Offline reyalp

  • ******
  • 14080
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #5 on: 26 / January / 2016, 21:36:40 »
Script is a wrapper to execute chdkptp commands.  (2) cameras are connected via USB bus; cameras have a shorted ON/OFF switch; powered on via wrapper script -> who calls an arduino application to close a relay.

Chdkptp is run " -i " inside a gnu 'screen' session.  Chdkptp operational commands are fed into the screen-session.  Wrapper script sleeps between 3-5 seconds between chdkptp commands - to give the camera a chance to respond. 
I'm still a little unclear how this works. You start one chdkptp session in each screen, end then feed individual CLI commands periodically?

If this is correct, does the chdkptp connect only happen when the screen is first started, or do you connect/disconnect for each command?

In general, I'd suggest leaving the connection open, but this may cause problems connecting by serial number.
Quote
Example of wrapper script executing chdkptp command below;  I do not yet pass the camera serial number as a variable (it's on the list.) 
Note that connecting by serial number attempts to make a connection to every camera on the USB bus, to get the serial number (the same is true for connecting by name, but not bus, device or product id). If there are other instances of CHDKPTP with active connections you will probably see messages like you reported:
Code: [Select]
Jan 24 06:45:08 zeus kernel: [721933.564704] usb 1-2: usbfs: interface 0 claimed by usbfs while 'chdkptp' sets config #1
Jan 24 06:45:08 zeus kernel: [721933.564731] usb 1-2: usbfs: process 21919 (chdkptp) did not claim interface 0 before use
in the log. I would not be surprised if this caused problems. I thought it completely killed the other connection, but in a quick test on ubuntu 14.04 it didn't seem to. It may depend on the specific linux verion, distro, hardware etc. In any case, I would not recommend connecting by name or serial number when using more than one instance of chdkptp.

This makes connecting to multiple cameras of the same model awkward. One option would be to do a "list" in one instance of chdkptp, and then use the device and bus info to connect the remaining instances. However, the device number may change if the camera is reconnected, rebooted etc.

Quote
Re: the dev id number 99;  No, that number increments once each time the usb device is seen by the host PC.  After a few hundred iterations and no NUC reboot, the number is, well, a few hundred, I guess.
Right, I was wondering if it happened specifically after 99 reconnects.

Quote
It may be that the chdkptp usb-reset you mentioned is what's biting me..
I don't know that it's a problem, but it's a bit of legacy code I have wondered about. I look into adding an option to control this, I've been meaning to do that for a while but never had a specific reason.
Quote
I played a little with multicam, but got hung up on making it exec 'remoteshoot' - which is quite handy for me.  I *could* simply have my wrapper let multicam save to SDcard, then go get images from SDcard instead of remoteshoot, but it was more code..   gotta not be lazy..
If your application doesn't require the cameras to shoot at the same moment with the exact same settings, multicam may not be a very good solution.

If you want to control multiple cameras, without shooting at the same time, you can just swap the global connection object (named con) around and use normal cli commands. e.g

Code: [Select]
connect -s=<cam 1 serial>
!cam1_con=con
connect -s=<cam 2 serial> -nodis
!cam2_con=con
The -nodis option tells chdkptp not to close the existing connection when it connects to the new camera.
Now you have two connection objects, and you can just set con to point to the one you want to control, like
Code: [Select]
!con=cam1_con
remoteshoot ....
!con=cam2_con
remoteshoot
...
Within a single chdkptp session, it's OK to connect to multiple cams by serial number, because it's aware of the existing connection.

If you do want to trigger the shutters at the exact same moment, remoteshoot is probably not good solution. While you could theoretically implement it with multicam, the actual data download would be sequential anyway so there wouldn't be much advantage over shooting and doing a image download/delete after.
Don't forget what the H stands for.

*

Offline axman

  • ***
  • 145
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #6 on: 27 / January / 2016, 15:08:05 »
Quote
I'm still a little unclear how this works. You start one chdkptp session in each screen, end then feed individual CLI commands periodically?
Correct.  Screens are detached, background processes that continue to run until they are terminated or error.
Quote
If this is correct, does the chdkptp connect only happen when the screen is first started, or do you connect/disconnect for each command?
Screen session is started, running chdkptp -i (it's detached, in the background)
chdkptp -i continues to run inside that screen, I do not disconnect/reconnect for each command given.
Screen session logfile is flushed
Camera is powered on, sleep 5
The 'chdkptp connect' command is given {using serial number,} sleep 4
chdkptp rec command is given, sleep 4
chdkptp remoteshoot command is given, sleep 4
chdkptp play command is given, sleep 4 {retract the lens}
chdkptp post_levent_to_ui Off command is given, sleep 1
 note that cam remains electrically powered ON for 1 sec because of shorted switch
cam is powered off
chdkptp session is quit, screen session is terminated
Quote
In general, I'd suggest leaving the connection open, but this may cause problems connecting by serial number.
I believe I am leaving the chdkptp connection open in the manner that I think you suggest.
Quote
Example of wrapper script executing chdkptp command below;  I do not yet pass the camera serial number as a variable (it's on the list.) 

Note that connecting by serial number attempts to make a connection to every camera on the USB bus, to get the serial number (the same is true for connecting by name, but not bus, device or product id). If there are other instances of CHDKPTP with active connections you will probably see messages like you reported:
Code: [Select]
Jan 24 06:45:08 zeus kernel: [721933.564704] usb 1-2: usbfs: interface 0 claimed by usbfs while 'chdkptp' sets config #1
Jan 24 06:45:08 zeus kernel: [721933.564731] usb 1-2: usbfs: process 21919 (chdkptp) did not claim interface 0 before use
in the log. I would not be surprised if this caused problems. I thought it completely killed the other connection, but in a quick test on ubuntu 14.04 it didn't seem to. It may depend on the specific linux verion, distro, hardware etc. In any case, I would not recommend connecting by name or serial number when using more than one instance of chdkptp.

This makes connecting to multiple cameras of the same model awkward. One option would be to do a "list" in one instance of chdkptp, and then use the device and bus info to connect the remaining instances. However, the device number may change if the camera is reconnected, rebooted etc.
Yes, I understand now.  I thought that using serial number would be the way to avoid contention / disruption on usb bus (in the case where >1 cameras are present, and >1 instances of chdkptp were running.)  But I see now that it's probably just blind luck of the cycle timing that my stuff works at all.!.   and it should actually be more likely to fail - fail more frequently - given what you've explained.
Quote
I played a little with multicam, but got hung up on making it exec 'remoteshoot' - which is quite handy for me.  I *could* simply have my wrapper let multicam save to SDcard, then go get images from SDcard instead of remoteshoot, but it was more code..   gotta not be lazy..
Quote
If your application doesn't require the cameras to shoot at the same moment with the exact same settings, multicam may not be a very good solution.

If you want to control multiple cameras, without shooting at the same time, you can just swap the global connection object (named con) around and use normal cli commands. e.g

Code: [Select]
connect -s=<cam 1 serial>
!cam1_con=con
connect -s=<cam 2 serial> -nodis
!cam2_con=con
The -nodis option tells chdkptp not to close the existing connection when it connects to the new camera.
Now you have two connection objects, and you can just set con to point to the one you want to control, like
Code: [Select]
!con=cam1_con
remoteshoot ....
!con=cam2_con
remoteshoot
...
Within a single chdkptp session, it's OK to connect to multiple cams by serial number, because it's aware of the existing connection.

If you do want to trigger the shutters at the exact same moment, remoteshoot is probably not good solution. While you could theoretically implement it with multicam, the actual data download would be sequential anyway so there wouldn't be much advantage over shooting and doing a image download/delete after.

Yes, I can see now, after this information, (Thanks, btw! :-D) that the way I've implemented chdkptp operations is likely the cause of the error.  I'm going to experiment with multicam, but with info you've given, I can also see how to continue with 'chdkptp remoteshoot' - by implementing a single chdkptp session that is speaking to multiple cameras - rather than having multiple chdkptp sessions speaking to a single cam.  Thanks again for the help.


*

Offline reyalp

  • ******
  • 14080
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #7 on: 27 / January / 2016, 16:01:57 »
I believe I am leaving the chdkptp connection open in the manner that I think you suggest.
It sounds like powering the camera on/off every shot, which explains the high dev numbers. In this case, leaving chdkptp connected is not really an option.

Quote
chdkptp post_levent_to_ui Off command is given, sleep 1
You may already be doing this, but I'd suggest a sequence like
. sleep(1000) post_levent_to_ui('PressPowerButton')
disconnect
(wait 2 sec, remove power)

The . command starts the lua code running, without waiting for it to finish. The sleep in the camera side lua code allows you to disconnect cleanly before the camera powers off.

Quote
Yes, I understand now.  I thought that using serial number would be the way to avoid contention / disruption on usb bus (in the case where >1 cameras are present, and >1 instances of chdkptp were running.)
FWIW, I suspect it be possible to get the serial number without disrupting existing connections, it's logged in the kernel log, so something somewhere must know it. But I don't actually know much about linux USB code.

Quote
Yes, I can see now, after this information, (Thanks, btw! :-D) that the way I've implemented chdkptp operations is likely the cause of the error.
I'm not totally sure this is causing your error, but it's seems possible.
Don't forget what the H stands for.


*

Offline axman

  • ***
  • 145
Re: chdkptp & IXUS160 - strange usbfs error
« Reply #8 on: 03 / February / 2016, 14:04:48 »
Quote
Quote

Within a single chdkptp session, it's OK to connect to multiple cams by serial number, because it's aware of the existing connection.

If you do want to trigger the shutters at the exact same moment, remoteshoot is probably not good solution. While you could theoretically implement it with multicam, the actual data download would be sequential anyway so there wouldn't be much advantage over shooting and doing a image download/delete after.
Yes, I can see now, after this information, (Thanks, btw! :-D) that the way I've implemented chdkptp operations is likely the cause of the error.  I'm going to experiment with multicam, but with info you've given, I can also see how to continue with 'chdkptp remoteshoot' - by implementing a single chdkptp session that is speaking to multiple cameras - rather than having multiple chdkptp sessions speaking to a single cam.  Thanks again for the help.

I confirm that the strange usb error was due to multiple instances of chdkptp 'remoteshoot' colliding with each other.  I fixed my code to use a single chdkptp instance; no errors since.  Substituting multicam for remoteshoot also works fine.

 

Related Topics