initial startup fails when camera is attached

[Al]

When I start RPD and the camera is attached it fails. When I start RPD without the camera attached and then plug it in it works.

starting using ubuntu 16.4, gnome desktop
Traceback (most recent call last):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 1086, in initStage9
    self.searchForCameras(on_startup=True)
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 4517, in searchForCameras
    on_startup=on_startup):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 4409, in unmountCameraToEnableScan
    if self.gvolumeMonitor.unmountCamera(model=model, port=port, on_startup=on_startup):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/storage.py", line 1189, in unmountCamera
    to_unmount = self.cameraMountPoint(model, port)
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/storage.py", line 1153, in cameraMountPoint
    assert p is not None
AssertionError

from log file

2017-06-01 07:25:00 INFO rapid.py 5734: Rapid Photo Downloader is starting
2017-06-01 07:25:02 INFO rapid.py 471: Rapid Photo Downloader: 0.9.0b5
2017-06-01 07:25:02 INFO rapid.py 471: Platform: Linux-4.4.0-78-generic-x86_64-with-Ubuntu-16.04-xenial
2017-06-01 07:25:02 INFO rapid.py 471: Python: 3.5.2
2017-06-01 07:25:02 INFO rapid.py 471: Qt: 5.5.1
2017-06-01 07:25:02 INFO rapid.py 471: PyQt: 5.5.1
2017-06-01 07:25:02 INFO rapid.py 471: ZeroMQ: 4.1.2
2017-06-01 07:25:02 INFO rapid.py 471: Python ZeroMQ: 15.1.0 (cython backend)
2017-06-01 07:25:02 INFO rapid.py 471: gPhoto2: 2.5.9
2017-06-01 07:25:02 INFO rapid.py 471: Python gPhoto2: 1.5.1
2017-06-01 07:25:02 INFO rapid.py 471: ExifTool: 10.10
2017-06-01 07:25:02 INFO rapid.py 471: pymediainfo: 2.1.9
2017-06-01 07:25:02 INFO rapid.py 471: GExiv2: 0.10.03
2017-06-01 07:25:02 INFO rapid.py 471: psutil: 3.4.2
2017-06-01 07:25:02 INFO rapid.py 471: Exiv2: 0.25.0
2017-06-01 07:25:03 INFO rapid.py 515: Device autodetection: True
2017-06-01 07:25:03 INFO rapid.py 521: For automatically detected devices, only the contents of their DCIM folder will be scanned
2017-06-01 07:25:03 INFO rapid.py 538: This Computer is not used as a download source
2017-06-01 07:25:03 INFO rapid.py 542: Photo download location: /home/mral/Pictures/2013-05-19
2017-06-01 07:25:03 INFO rapid.py 545: Video download location: /home/mral/Videos
2017-06-01 07:25:03 INFO rapid.py 550: Backing up files: False
2017-06-01 07:25:03 DEBUG rapid.py 589: Starting main ExifTool process
2017-06-01 07:25:03 DEBUG preferences.py 889: Validating CPU core count for thumbnail generation...
2017-06-01 07:25:03 DEBUG preferences.py 891: ...4 physical cores detected
2017-06-01 07:25:03 DEBUG rapid.py 694: Starting logging subscription manager...
2017-06-01 07:25:03 DEBUG rapid.py 699: ...logging subscription manager started
2017-06-01 07:25:03 DEBUG rapid.py 704: Stage 2 initialization
2017-06-01 07:25:03 DEBUG rapid.py 730: Starting thumbnail daemon model
2017-06-01 07:25:03 DEBUG interprocess.py 279: Running sink for Thumbnail Daemon Manager
2017-06-01 07:25:03 DEBUG rapid.py 743: Stage 3 initialization
2017-06-01 07:25:03 DEBUG rapid.py 748: ...thumbnail daemon model started
2017-06-01 07:25:03 DEBUG interprocess.py 691: Starting worker for Thumbnail Daemon Manager
2017-06-01 07:25:03 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbnaildaemon.py --receive 43563 --send 42469 --logging 34456' with pid 12446
2017-06-01 07:25:03 DEBUG thumbnailer.py 179: Starting thumbnail model...
2017-06-01 07:25:03 DEBUG interprocess.py 279: Running sink for Thumbnail Manager
2017-06-01 07:25:03 DEBUG thumbnailer.py 197: ...thumbnail model started
2017-06-01 07:25:03 DEBUG thumbnailer.py 202: Starting thumbnail load balancer...
2017-06-01 07:25:03 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbloadbalancer.py --receive 42527 --send 41647 --controller 44560 --logging 34456' with pid 12449
2017-06-01 07:25:04 DEBUG interprocess.py 1165: Subscribing to logging on port 41937
2017-06-01 07:25:04 DEBUG interprocess.py 1165: Subscribing to logging on port 33514
2017-06-01 07:25:04 DEBUG thumbnailer.py 214: ...thumbnail load balancer started
2017-06-01 07:25:04 DEBUG rapid.py 760: Stage 4 initialization
2017-06-01 07:25:04 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbnailextractor.py --request 45736 --send 41647 --identity 0 --logging 34456' with pid 12458
2017-06-01 07:25:04 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbnailextractor.py --request 45736 --send 41647 --identity 1 --logging 34456' with pid 12459
2017-06-01 07:25:04 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbnailextractor.py --request 45736 --send 41647 --identity 2 --logging 34456' with pid 12460
2017-06-01 07:25:04 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/thumbnailextractor.py --request 45736 --send 41647 --identity 3 --logging 34456' with pid 12461
2017-06-01 07:25:05 DEBUG rapid.py 782: Default file manager: nemo
2017-06-01 07:25:05 DEBUG rapid.py 795: Locale directory: /home/mral/.local/share/locale
2017-06-01 07:25:05 DEBUG rapid.py 798: Getting gphoto2 context
2017-06-01 07:25:05 DEBUG rapid.py 805: Probing for valid mounts
2017-06-01 07:25:05 DEBUG storage.py 247: Media dir is /media/mral
2017-06-01 07:25:05 DEBUG storage.py 294: To be recognized, partitions must be mounted under /media/mral
2017-06-01 07:25:05 DEBUG rapid.py 809: Freedesktop.org thumbnails location: /home/mral/.cache/thumbnails
2017-06-01 07:25:05 DEBUG rapid.py 811: Probing desktop environment
2017-06-01 07:25:05 DEBUG rapid.py 814: Desktop environment: GNOME-Flashback:Unity
2017-06-01 07:25:05 DEBUG rapid.py 838: Have GIO module: True
2017-06-01 07:25:05 DEBUG rapid.py 841: Using GIO: True
2017-06-01 07:25:05 DEBUG rapid.py 871: Starting GVolumeMonitor...
2017-06-01 07:25:05 DEBUG rapid.py 873: ...GVolumeMonitor started
2017-06-01 07:25:05 DEBUG rapid.py 1830: Checking path validity
2017-06-01 07:25:05 DEBUG storage.py 750: Updating watched paths
2017-06-01 07:25:05 DEBUG storage.py 764: Adding to watched paths: /home/mral/Pictures, /home/mral
2017-06-01 07:25:06 DEBUG rapid.py 884: Laying out main window
2017-06-01 07:25:06 DEBUG renamepanel.py 143: Setting photo combobox chosen value to Custom...
2017-06-01 07:25:06 DEBUG renamepanel.py 231: Updating example photo name in rename panel
2017-06-01 07:25:06 DEBUG renamepanel.py 143: Setting video combobox chosen value to Original Filename
2017-06-01 07:25:06 DEBUG renamepanel.py 234: Updating example video name in rename panel
2017-06-01 07:25:06 DEBUG jobcodepanel.py 296: Inserting 4 job codes into job code widget
2017-06-01 07:25:06 DEBUG storage.py 247: Media dir is /media/mral
2017-06-01 07:25:06 DEBUG storage.py 294: To be recognized, partitions must be mounted under /media/mral
2017-06-01 07:25:06 DEBUG foldercombo.py 74: Rebuilding photo combobox entries...
2017-06-01 07:25:07 DEBUG interprocess.py 1165: Subscribing to logging on port 41289
2017-06-01 07:25:07 DEBUG interprocess.py 1165: Subscribing to logging on port 35284
2017-06-01 07:25:07 DEBUG interprocess.py 1165: Subscribing to logging on port 35142
2017-06-01 07:25:07 DEBUG interprocess.py 1165: Subscribing to logging on port 34930
2017-06-01 07:25:07 DEBUG foldercombo.py 158: ...11 combobox entries added
2017-06-01 07:25:07 INFO foldercombo.py 210: photo path /home/mral is a default value or path to an external volume
2017-06-01 07:25:07 DEBUG foldercombo.py 74: Rebuilding video combobox entries...
2017-06-01 07:25:07 DEBUG foldercombo.py 158: ...11 combobox entries added
2017-06-01 07:25:07 INFO foldercombo.py 210: video path /home/mral is a default value or path to an external volume
2017-06-01 07:25:07 DEBUG rapid.py 888: Starting version check
2017-06-01 07:25:08 DEBUG rapid.py 918: Starting download tracker
2017-06-01 07:25:08 DEBUG rapid.py 925: Setting up download update timer
2017-06-01 07:25:08 DEBUG rapid.py 932: Starting offload manager...
2017-06-01 07:25:09 DEBUG interprocess.py 279: Running sink for Offload Manager
2017-06-01 07:25:09 DEBUG rapid.py 946: ...offload manager started
2017-06-01 07:25:09 DEBUG rapid.py 971: Starting rename manager...
2017-06-01 07:25:09 DEBUG interprocess.py 279: Running sink for Rename and Move File Manager
2017-06-01 07:25:09 DEBUG interprocess.py 691: Starting worker for Offload Manager
2017-06-01 07:25:09 DEBUG rapid.py 976: ...rename manager started
2017-06-01 07:25:09 DEBUG interprocess.py 691: Starting worker for Rename and Move File Manager
2017-06-01 07:25:09 DEBUG rapid.py 997: Starting scan manager...
2017-06-01 07:25:09 DEBUG interprocess.py 279: Running sink for Scan Manager
2017-06-01 07:25:09 DEBUG rapid.py 1002: ...scan manager started
2017-06-01 07:25:09 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/offload.py --receive 39598 --send 33284 --logging 34456' with pid 12495
2017-06-01 07:25:09 DEBUG rapid.py 1021: Starting copy files manager...
2017-06-01 07:25:09 DEBUG interprocess.py 279: Running sink for Copy Files Manager
2017-06-01 07:25:09 DEBUG rapid.py 1026: ...copy files manager started
2017-06-01 07:25:09 DEBUG rapid.py 1043: Starting backup manager ...
2017-06-01 07:25:09 DEBUG interprocess.py 279: Running sink for Backup Manager
2017-06-01 07:25:09 DEBUG rapid.py 1048: ...backup manager started
2017-06-01 07:25:09 DEBUG interprocess.py 183: Started '/usr/bin/python3 /home/mral/.local/lib/python3.5/site-packages/raphodo/renameandmovefile.py --receive 34918 --send 38183 --logging 34456' with pid 12496
2017-06-01 07:25:09 DEBUG rpdsql.py 283: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>]
2017-06-01 07:25:09 DEBUG rpdsql.py 283: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>]
2017-06-01 07:25:10 ERROR devices.py 213: Could not determine udev values for Nikon D100 (Sierra Mode) usbscsi:/dev/sg4
2017-06-01 07:25:10 DEBUG interprocess.py 1165: Subscribing to logging on port 39641
2017-06-01 07:25:10 DEBUG rapid.py 4510: Detected Nikon D100 (Sierra Mode) on port usbscsi:/dev/sg4
2017-06-01 07:25:10 ERROR excepthook.py 67: An unhandled exception occurred
2017-06-01 07:25:10 ERROR excepthook.py 68: Traceback (most recent call last):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 1086, in initStage9
    self.searchForCameras(on_startup=True)
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 4517, in searchForCameras
    on_startup=on_startup):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/rapid.py", line 4409, in unmountCameraToEnableScan
    if self.gvolumeMonitor.unmountCamera(model=model, port=port, on_startup=on_startup):
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/storage.py", line 1189, in unmountCamera
    to_unmount = self.cameraMountPoint(model, port)
  File "/home/mral/.local/lib/python3.5/site-packages/raphodo/storage.py", line 1153, in cameraMountPoint
    assert p is not None
AssertionError

2017-06-01 07:25:11 DEBUG interprocess.py 1165: Subscribing to logging on port 45502

[Damon Lynch (dlynch3)]

Thanks for your bug report.

Please attach to this bug report all the log files found in ~/.cache/rapid-photo-downloader/log

Also, while Rapid Photo Downloader is not running, insert the D100 and start nemo. I don't use nemo so I don't know how it differs from Gnome Files, but what I need is the exact address of the camera in the location bar. In Gnome Files it's just a matter of hitting the key combination Ctrl-l. Copy and paste the displayed value in this bug report. It should start with gphoto2://

[Al (alpinekid-p)]

having trouble finding anything with a gphoto:// prefix

does this help

$ gphoto2 --auto-detect
Model Port
----------------------------------------------------------
Mass Storage Camera disk:/media/mral/NIKON D100
Nikon D100 (Sierra Mode) usbscsi:/dev/sg4
mral@ATR20140614:~$

or from lsusb

Bus 004 Device 005: ID 04b0:0401 Nikon Corp.

Thanks for your attention to this.

I'm still figuring out how to attach files, I'll get back to you when I figure it out.

[Al (alpinekid-p)]

here is the whole log file.

[Damon Lynch (dlynch3)]

That's very useful information, thanks. It looks like the camera is mounted very differently to other cameras, so the code I need to check to see if it's mounted or not needs to be different in more than one respect. It looks like the gphoto2:// prefix is not used at all.

[Al (alpinekid-p)]

I'm happy to help test. I don't believe in crying wolf so this is not holding me up, I have the work around, just plug it in after starting your program. so prioritize as you see fit.

[Damon Lynch (dlynch3)]

With your D100 camera plugged in to your computer (and no other camera or smart phone plugged in), ensure the camera is showing in your file browser and is mounted, and the from the command run this:

gphoto2 --list-files

If it displays the cameras files to you without indicating an error, that could be a useful sign (it's not important that I know the filenames, no need to copy and paste them here).

Also, can the D100 be put into PTP mode?

[Al (alpinekid-p)]

The camera does show up as a device and i can treat it like another of device.

The results of the gphoto --list-files

typical line is
#1 DSC_5245.NEF rd 9766 KB image/x-raw

The menu does have a PTP mode the the usb but I have never used it. I dont really know what that mode is for. I always threat all my camera as filesystems.

I got your email is how I found out about this request. I'll have to look into figuring out the get this bug system to send the request directly. I was expecting that so I was not going here every day.

[Al (alpinekid-p)]

I just download version 0.9.0b6.

I appears that the issue I was having has gone away.
I have the Nikon D100 plugged into the usb bus and its powered up and the RPD see it.

I'm no longer able to produce the symptom that caused me to post this bug report.

Thanks for your work.