Crash waiting for events with Nikon D800 Camera about sequoia-ptpy HOT 19 CLOSED

Hi @aaronhourie,

Could you please pull the latest master and try again with PTPY_DEBUG=1 and PTPY_DEBUG_LOG="./PTPy.log" in your environment?

This should create a file PTPy.log in the current directory that would allow me to see what's up.

Thanks,

from sequoia-ptpy.

I changed the extension so I could upload it to Github.

PTPy.log.txt

Please let me know if you need any other information.

from sequoia-ptpy.

Thanks!

Could you pull master again and attempt to reproduce the crash while logging?
This is to see why parsing failed on the event after initiating a capture.
(I don't see any events on that log)

from sequoia-ptpy.

Here's the PTP log:
PTPy.txt

Here's all the standard error and standard output to a file, if you want to track down when the FieldError exception is thrown.
alloutput.txt

from sequoia-ptpy.

I've just pushed a small modification that will avoid crashes on empty reads and will also log data in case it is not quite empty.

Could you please confirm the bug disappears or report back?
Thank you!

from sequoia-ptpy.

I'm afraid it's still crashing, here are the logs and the output

PTPy.txt
alloutput.txt

Please let me know if there's any other info you need.

from sequoia-ptpy.

I've pushed another small modification.
If you still notice the crash, could you declare in your environment PYUSB_DEBUG='debug' without declaring the PTPY variables?

And run this (very) simplified script instead?

#/usr/bin/env python
from ptpy import PTPy
from time import sleep
c = PTPy(raw=True)
while True:
    sleep(1)

This will essentially do nothing other than wait for events and exit cleanly on KeyboardInterrupt.

Thank you for the follow-up.

from sequoia-ptpy.

No worries! Thanks for helping me out with this.

That update seems to work if I use it to wait for events, as it doesn't crash when I snap a picture (it did before). However, if I initiate a capture from the code, then wait for events I get the same exception.

Here's the output from your script with PyUSB logging turned on.
alloutput.txt

This is the script I am running:

from ptpy import PTPy
import time

camera = PTPy()

with camera.session() :
  has_event = False
  while not has_event :
    camera.initiate_capture()
    event = camera.event()
    if event :
      print(event)
    time.sleep(1)

Here is the output (with PyUsb logging):
my_camera_output.txt

from sequoia-ptpy.

I get a feeling the camera is having trouble keeping up with the requests. It is answering DeviceBusy to most of them. And also all event reads are empty...

Nikon cameras must have some different mechanism to check for events.
And might require further interaction before being able to handle more successful triggers.

Would you please, with both PYUSB_DEBUG='debug' and PTPY_DEBUG=1:

• Print the result of print_device_info.py in the examples folder.
• Launch your script.
• Launch poll_events.py in the examples folder while you change settings on the camera. (Aperture, exposure time, ...)

Thanks,

from sequoia-ptpy.

Here is the output from print_device_info.py
print_device_info.txt

Here is the output for my script:
my_camera.txt

Here is the output for poll_events.py:
print_device_info.txt

from sequoia-ptpy.

Thank you. I think the last log is not from an event polling.

It seems it was a CaptureComplete event, which didn't quite make it through.
I've modified the timeouts a bit. Could you please check again?

I've also sketched a Nikon extension (check the README on how to impose it).
I have a feeling check_events and capture methods will be useful. It is possible that the camera expects vendor-specific events to be polled regularly.

from sequoia-ptpy.

Sorry about that, I dragged the wrong file in. Here's the output for poll_events
poll_events.txt

With this script:

from ptpy import PTPy
from ptpy.extensions.nikon import PTPDevice as nikon
import time

camera = PTPy(extension=nikon)
with camera.session() :
  while True:
    camera.capture()
    event = camera.check_events()
    if event :
      print(event)
    time.sleep(1)

I got the following output:

DEBUG 2017-06-29 08:33:29 root[MainThread] Determining available transports
DEBUG 2017-06-29 08:33:29 root[MainThread] Imposing <class 'ptpy.extensions.nikon.PTPDevice'> extension
DEBUG 2017-06-29 08:33:29 ptpy.transports.usb[MainThread] Init USB
Traceback (most recent call last):
  File "my_camera.py", line 5, in <module>
    camera = PTPy(extension=nikon)
  File "/home/pi/github/sequoia-ptpy/ptpy/__init__.py", line 104, in __new__
    instance = PTPy(device)
  File "/home/pi/github/sequoia-ptpy/ptpy/transports/usb.py", line 78, in __init__
    self.__setup_constructors()
  File "/home/pi/github/sequoia-ptpy/ptpy/transports/usb.py", line 207, in __setup_constructors
    self._set_endian('little')
  File "/home/pi/github/sequoia-ptpy/ptpy/extensions/nikon.py", line 397, in _set_endian
    ptp.PTPDevice._set_endian(self, endian)
  File "/home/pi/github/sequoia-ptpy/ptpy/ptp.py", line 674, in _set_endian
    self._PropertyCode = self._PropertyCode()
  File "/home/pi/github/sequoia-ptpy/ptpy/extensions/nikon.py", line 305, in _PropertyCode
    **product_properties
TypeError: _PropertyCode() argument after ** must be a mapping, not NoneType

Let me know if you need more testing done with the Nikon camera, I'd be happy to help.

from sequoia-ptpy.

Oops. I might have pushed that too quickly. The very basic Nikon support should work now.

Have you had event parsing crashes with the timing modifications?

from sequoia-ptpy.

So, with that most recent update, and the same script as before I found that camera.capture() doesn't trigger a capture on the camera. Taking a picture manually seems to work properly with the new camera.check_events() function.

Using camera.initiate_capture() followed by camera.check_events() causes the error to come up periodically, but the thread doesn't stop (where events would no longer be received) , as it did before.
When the error doesn't pop up, the event is registering properly.

Let me know what information you need.

from sequoia-ptpy.

Could you put a log up of the whole interaction you describe?

It might help figure out why PTPy is not getting an entire transaction header (even after five seconds). It could be an uncleared USB halt.

The check_events function does not actually poll events in the background at all... It is a Nikon specific operation independent of the PTP event thread.

As of 03af0a3, the events thread should report errors but not stop.

from sequoia-ptpy.

Here is the log for checking events after initiating a capture:
nikon_output.txt

from sequoia-ptpy.

I haven't had much time to look in detail into this.
It seems that events are getting stuck for some reason.
The error you see is an Object Added event being added that doesn't finish its transfer over in over 5 seconds...

I've added support to the Nikon extension to poll for Nikon events automatically during a session so you don't have to do it. The events of the Nikon extension will then be available through the same event method as before.

I've also added several small reads to replace a longer read with a large timeout.
I don't see any indication of a USB halt.

Could you have a look when you get the time to see if the changes help things?

Thanks for your feedback!

from sequoia-ptpy.

It seems like it works properly. It now recognizes all of the events coming out of the camera, and gives me an event code each time. Is there any output you'd like, or more tests you want me to run?

Thanks for spending the time on this!

from sequoia-ptpy.

Good!

I'd appreciate feedback if things don't quite work.
Nothing specific for the time being.

from sequoia-ptpy.