Activity log for bug #1813565

Date Who What changed Old value New value Message
2019-01-28 11:54:41 Franck78 bug added bug
2019-01-28 15:24:59 Damon Lynch rapid: status New Incomplete
2019-01-29 23:37:03 Franck78 attachment added log file (full) https://bugs.launchpad.net/rapid/+bug/1813565/+attachment/5233949/+files/rapid-photo-downloader.log
2019-01-29 23:38:32 Franck78 description In short Fresh UBUNTU 18.04, install.py went OK /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 is a readonly samba share mounted on the machine running rpd Scanning ends with an exception. Looks like permissions (read only) on the samba server share are affecting the locally job. Here is the log (two try) 2019-01-28 03:01:53 DEBUG proximity.py 1989: Updating Timeline state from empty to generating 2019-01-28 03:01:53 DEBUG devices.py 565: Setting device state for avendre to thumbnailing 2019-01-28 03:01:53 DEBUG rapid.py 1605: Setting progress bar maximum to 250 2019-01-28 03:01:53 DEBUG rpdsql.py 480: SELECT uid FROM files WHERE scan_id=? (2, ) 2019-01-28 03:01:53 DEBUG interprocess.py 192: Started '/usr/bin/python3 /home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py --receive 38243 --send 46791 --controller 40533 --syncclient 39079 --filter 2 --logging 45151' with pid 16789 2019-01-28 03:01:54 INFO proximity.py 954: Timeline validation passed 2019-01-28 03:01:54 DEBUG proximity.py 1989: Updating Timeline state from generating to generated 2019-01-28 03:01:54 DEBUG rpdsql.py 474: UPDATE files SET proximity_col1=?, proximity_col2=? WHERE uid=? (250 operations) 2019-01-28 03:01:55 DEBUG interprocess.py 1213: Subscribing to logging on port 44431 2019-01-28 03:01:55 INFO thumbnailpara.py 458: Generating 250 thumbnails for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:01:55 DEBUG thumbnailextractor.py 620: Working on task load_from_exif for roco-digistart.jpg 2019-01-28 03:01:56 DEBUG thumbnailextractor.py 620: Working on task load_from_exif for rcs_telecommande.jpg 2019-01-28 03:01:56 ERROR thumbnailpara.py 449: Exception generating thumbnails for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:01:56 ERROR thumbnailpara.py 452: Traceback: Traceback (most recent call last): File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 444, in do_work self.generate_thumbnails() File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 736, in generate_thumbnails task = preprocess_thumbnail_from_disk(rpd_file=rpd_file, processing=processing) File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 303, in preprocess_thumbnail_from_disk with open(rpd_file.full_file_name, 'rb') as photo: PermissionError: [Errno 13] Permission non accordée: '/var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/Electricité/osram7w-840.jpg' 2019-01-28 03:01:56 WARNING metadataphoto.py 292: Unexpected malformed date time metadata value for photo /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/roco-digistart.jpg 2019-01-28 03:01:56 WARNING metadataphoto.py 378: Photo /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/roco-digistart.jpg has no image previews 2019-01-28 03:01:56 WARNING metadataphoto.py 378: Photo /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/rcs_telecommande.jpg has no image previews 2019-01-28 03:01:56 DEBUG cache.py 439: Saving thumbnail for file:///var/run/user/1000/gvfs/smb-share%3Aserver%3Dntkiller2.local%2Cshare%3Dtop/home/fbourdonnec/Images/avendre/roco-digistart.jpg in RPD thumbnail cache 2019-01-28 03:01:56 DEBUG cache.py 439: Saving thumbnail for file:///var/run/user/1000/gvfs/smb-share%3Aserver%3Dntkiller2.local%2Cshare%3Dtop/home/fbourdonnec/Images/avendre/rcs_telecommande.jpg in RPD thumbnail cache 2019-01-28 03:01:56 INFO thumbnaildisplay.py 793: Metadata time differs from file modification time for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/rcs_telecommande.jpg (with possibly more to come, but these will not be logged) 2019-01-28 03:01:56 DEBUG proximity.py 1989: Updating Timeline state from generated to ctime_rebuild 2019-01-28 03:01:56 INFO rapid.py 418: Cleaning provisional download folders for avendre 2019-01-28 03:01:56 DEBUG folderspreview.py 367: Cleaning subfolders created for scan id 2 2019-01-28 03:01:56 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:01:56 INFO rapid.py 4082: Need to rebuild timeline and subfolder previews for avendre Retry here 2019-01-28 03:02:23 DEBUG rapid.py 5137: Device removed: /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 924: Clearing all non-downloaded thumbnails for scan id 2 2019-01-28 03:02:23 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE scan_id=? AND downloaded=? [2, False] 2019-01-28 03:02:23 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE scan_id=? AND downloaded=? [2, False] 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 941: Removing 250 thumbnail and rpd_files rows 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 130: Purging 0 thumbnails from buffer 2019-01-28 03:02:23 DEBUG rpdsql.py 632: DELETE FROM files WHERE scan_id=? AND downloaded=? ([2, False]) 2019-01-28 03:02:23 DEBUG rapid.py 1605: Setting progress bar maximum to 2 2019-01-28 03:02:23 DEBUG rpdsql.py 638: DELETE FROM devices WHERE scan_id=? (2, ) 2019-01-28 03:02:23 DEBUG devicedisplay.py 224: Removing 2 rows from This Computer display, starting at row 0 2019-01-28 03:02:23 INFO rapid.py 418: Cleaning provisional download folders for avendre 2019-01-28 03:02:23 DEBUG folderspreview.py 367: Cleaning subfolders created for scan id 2 2019-01-28 03:02:23 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:02:23 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:02:23 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:02:23 DEBUG proximity.py 1989: Updating Timeline state from ctime_rebuild to empty 2019-01-28 03:02:23 DEBUG devices.py 507: -- Device Collection -- 2019-01-28 03:02:23 DEBUG devices.py 511: 0 devices: 0 volumes/cameras (0 cameras), 0 this computer 2019-01-28 03:02:23 DEBUG devices.py 515: Device states: 2019-01-28 03:02:23 DEBUG devices.py 520: No devices scanning 2019-01-28 03:02:23 DEBUG devices.py 527: No devices downloading 2019-01-28 03:02:23 DEBUG devices.py 534: No devices thumbnailing 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 240: -- Thumbnail Model -- 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 250: 0 thumbnails (0 marked) 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 255: 0 not downloaded; 0 downloaded; 0 previously downloaded 2019-01-28 03:02:23 DEBUG thumbnaildisplay.py 267: Active devices: (3 removed) 2019-01-28 03:02:23 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:05 DEBUG rapid.py 5416: Using This Computer path /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:05 DEBUG rapid.py 4893: Assigning scan id 3 to /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:05 DEBUG rpdsql.py 131: INSERT OR REPLACE INTO devices (scan_id, device_name) VALUES (?,?) (3, 2018) 2019-01-28 03:03:05 DEBUG devicedisplay.py 164: Adding /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 to This Computer display with scan id 3 at row 0 2019-01-28 03:03:05 DEBUG devices.py 565: Setting device state for 2018 to scanning 2019-01-28 03:03:05 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:05 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:05 DEBUG rapid.py 1611: Setting progress bar to show scanning activity 2019-01-28 03:03:05 DEBUG interprocess.py 192: Started '/usr/bin/python3 /home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py --receive 38113 --send 40797 --controller 35209 --syncclient 34969 --filter 3 --logging 45151' with pid 16805 2019-01-28 03:03:07 DEBUG interprocess.py 1213: Subscribing to logging on port 42141 2019-01-28 03:03:07 DEBUG scan.py 195: Scan 3 worker started 2019-01-28 03:03:07 INFO scan.py 248: Scanning This Computer path 2018 2019-01-28 03:03:07 DEBUG scan.py 1276: Distinguishing approach to timestamp time zones on 2018 2019-01-28 03:03:07 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018/2018-08-03_11-18-39.jpg 2019-01-28 03:03:07 INFO scan.py 1354: Device timezone setting for 2018 is unknown, because the file modification time and file's time as recorded in metadata differ for sample file jpeg 2019-01-28 03:03:07 INFO scan.py 908: Successfully extracted sample photo metadata from 2018 2019-01-28 03:03:08 DEBUG scan.py 886: Sending 2 scanned files from 2018 to sink 2019-01-28 03:03:08 INFO scan.py 406: 2 total files scanned on 2018 2019-01-28 03:03:08 DEBUG interprocess.py 1222: Unsubscribing to logging on port 42141 2019-01-28 03:03:08 DEBUG interprocess.py 336: Scan Manager currently has no workers 2019-01-28 03:03:08 INFO rapid.py 4255: Updating example file name using sample photo from 2018 2019-01-28 03:03:08 DEBUG renamepanel.py 238: Updating example photo name in rename panel 2019-01-28 03:03:08 DEBUG rapid.py 4497: No files are marked for download for 2018 2019-01-28 03:03:08 DEBUG devices.py 565: Setting device state for 2018 to idle 2019-01-28 03:03:08 DEBUG rpdsql.py 146: Adding 2 rows to db 2019-01-28 03:03:08 DEBUG rpdsql.py 284: SELECT uid, marked FROM files ORDER BY mtime ASC 2019-01-28 03:03:08 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:08 DEBUG devicedisplay.py 348: Setting 2018 checkbox to checked 2019-01-28 03:03:08 DEBUG devicedisplay.py 329: -- Device Model for This Computer -- 2019-01-28 03:03:08 DEBUG devicedisplay.py 331: Known devices: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 336: Row 0: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 336: Row 1: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 339: Spinner states: 2018: scanning 2019-01-28 03:03:08 DEBUG devicedisplay.py 341: 2018: checked 2019-01-28 03:03:08 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:08 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:08 DEBUG devices.py 507: -- Device Collection -- 2019-01-28 03:03:08 DEBUG devices.py 511: 1 devices: 0 volumes/cameras (0 cameras), 1 this computer 2019-01-28 03:03:08 DEBUG devices.py 515: Device states: 2018: idle 2019-01-28 03:03:08 DEBUG devices.py 520: No devices scanning 2019-01-28 03:03:08 DEBUG devices.py 527: No devices downloading 2019-01-28 03:03:08 DEBUG devices.py 534: No devices thumbnailing 2019-01-28 03:03:08 DEBUG thumbnaildisplay.py 240: -- Thumbnail Model -- 2019-01-28 03:03:08 DEBUG thumbnaildisplay.py 250: 2 thumbnails (2 marked) 2019-01-28 03:03:08 DEBUG thumbnaildisplay.py 255: 2 not downloaded; 0 downloaded; 0 previously downloaded 2019-01-28 03:03:08 DEBUG thumbnaildisplay.py 259: 2 to be generated; 0 generated 2019-01-28 03:03:08 DEBUG thumbnaildisplay.py 267: Active devices: 2018 (3 removed) 2019-01-28 03:03:08 DEBUG devicedisplay.py 329: -- Device Model for This Computer -- 2019-01-28 03:03:08 DEBUG devicedisplay.py 331: Known devices: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 336: Row 0: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 336: Row 1: 2018 2019-01-28 03:03:08 DEBUG devicedisplay.py 339: Spinner states: 2018: scanning 2019-01-28 03:03:08 DEBUG devicedisplay.py 341: 2018: checked 2019-01-28 03:03:08 INFO rapid.py 4530: Generating Timeline because a download source has finished being scanned 2019-01-28 03:03:08 DEBUG proximity.py 1989: Updating Timeline state from empty to generating 2019-01-28 03:03:08 DEBUG devices.py 565: Setting device state for 2018 to thumbnailing 2019-01-28 03:03:08 DEBUG rapid.py 1605: Setting progress bar maximum to 2 2019-01-28 03:03:08 DEBUG rpdsql.py 480: SELECT uid FROM files WHERE scan_id=? (3, ) 2019-01-28 03:03:08 INFO proximity.py 954: Timeline validation passed 2019-01-28 03:03:08 DEBUG interprocess.py 192: Started '/usr/bin/python3 /home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py --receive 38243 --send 46791 --controller 40533 --syncclient 39079 --filter 3 --logging 45151' with pid 16908 2019-01-28 03:03:08 DEBUG rapid.py 319: Provisional download folders received 2019-01-28 03:03:08 DEBUG rapid.py 326: Provisional download folders change detected 2019-01-28 03:03:08 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:03:08 DEBUG proximity.py 1989: Updating Timeline state from generating to generated 2019-01-28 03:03:08 DEBUG rpdsql.py 474: UPDATE files SET proximity_col1=?, proximity_col2=? WHERE uid=? (2 operations) 2019-01-28 03:03:10 DEBUG interprocess.py 1213: Subscribing to logging on port 38095 2019-01-28 03:03:10 INFO thumbnailpara.py 458: Generating 2 thumbnails for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:10 DEBUG thumbnailextractor.py 620: Working on task load_from_exif for 2018-08-03_11-18-39.jpg 2019-01-28 03:03:10 DEBUG thumbnailpara.py 783: Finished phase 1 of thumbnail generation for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:10 DEBUG interprocess.py 1222: Unsubscribing to logging on port 38095 2019-01-28 03:03:10 DEBUG thumbnailextractor.py 620: Working on task load_from_exif for 2018-08-03_11-30-12.jpg 2019-01-28 03:03:11 DEBUG cache.py 439: Saving thumbnail for file:///var/run/user/1000/gvfs/smb-share%3Aserver%3Dntkiller2.local%2Cshare%3Dtop/home/fbourdonnec/Images/2018/2018-08-03_11-18-39.jpg in RPD thumbnail cache 2019-01-28 03:03:11 DEBUG cache.py 439: Saving thumbnail for file:///var/run/user/1000/gvfs/smb-share%3Aserver%3Dntkiller2.local%2Cshare%3Dtop/home/fbourdonnec/Images/2018/2018-08-03_11-30-12.jpg in RPD thumbnail cache 2019-01-28 03:03:11 INFO thumbnaildisplay.py 793: Metadata time differs from file modification time for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018/2018-08-03_11-30-12.jpg (with possibly more to come, but these will not be logged) 2019-01-28 03:03:11 DEBUG proximity.py 1989: Updating Timeline state from generated to ctime_rebuild 2019-01-28 03:03:11 INFO rapid.py 418: Cleaning provisional download folders for 2018 2019-01-28 03:03:11 DEBUG folderspreview.py 367: Cleaning subfolders created for scan id 3 2019-01-28 03:03:11 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:03:11 INFO rapid.py 4082: Need to rebuild timeline and subfolder previews for 2018 2019-01-28 03:03:11 DEBUG devices.py 565: Setting device state for 2018 to idle 2019-01-28 03:03:11 INFO thumbnaildisplay.py 756: Finished thumbnail generation for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:11 DEBUG rpdsql.py 480: SELECT uid FROM files WHERE scan_id=? (3, ) 2019-01-28 03:03:11 INFO rapid.py 269: Generating provisional download folders for 2 files 2019-01-28 03:03:11 DEBUG proximity.py 1974: Timeline is ready to be rebuilt after ctime change 2019-01-28 03:03:11 INFO rapid.py 4530: Generating Timeline because a photo or video's creation time differed from its file system modification time 2019-01-28 03:03:11 DEBUG proximity.py 1989: Updating Timeline state from ctime_rebuild_proceed to generating 2019-01-28 03:03:11 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:11 INFO proximity.py 954: Timeline validation passed 2019-01-28 03:03:11 DEBUG thumbnaildisplay.py 240: -- Thumbnail Model -- 2019-01-28 03:03:11 DEBUG thumbnaildisplay.py 250: 2 thumbnails (2 marked) 2019-01-28 03:03:11 DEBUG thumbnaildisplay.py 255: 2 not downloaded; 0 downloaded; 0 previously downloaded 2019-01-28 03:03:11 DEBUG thumbnaildisplay.py 267: Active devices: 2018 (3 removed) 2019-01-28 03:03:11 DEBUG rapid.py 319: Provisional download folders received 2019-01-28 03:03:11 DEBUG rapid.py 326: Provisional download folders change detected 2019-01-28 03:03:11 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:03:11 DEBUG proximity.py 1989: Updating Timeline state from generating to generated 2019-01-28 03:03:11 DEBUG rpdsql.py 474: UPDATE files SET proximity_col1=?, proximity_col2=? WHERE uid=? (2 operations) 2019-01-28 03:03:17 DEBUG rapid.py 2717: Removing path from device view /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:17 INFO rapid.py 5135: Device removed: /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 2019-01-28 03:03:17 DEBUG thumbnaildisplay.py 924: Clearing all non-downloaded thumbnails for scan id 3 2019-01-28 03:03:17 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE scan_id=? AND downloaded=? [3, False] 2019-01-28 03:03:17 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE scan_id=? AND downloaded=? [3, False] 2019-01-28 03:03:17 DEBUG thumbnaildisplay.py 941: Removing 2 thumbnail and rpd_files rows 2019-01-28 03:03:17 DEBUG thumbnaildisplay.py 130: Purging 0 thumbnails from buffer 2019-01-28 03:03:17 DEBUG rpdsql.py 632: DELETE FROM files WHERE scan_id=? AND downloaded=? ([3, False]) 2019-01-28 03:03:17 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:17 DEBUG rpdsql.py 638: DELETE FROM devices WHERE scan_id=? (3, ) 2019-01-28 03:03:17 DEBUG devicedisplay.py 224: Removing 2 rows from This Computer display, starting at row 0 2019-01-28 03:03:17 INFO rapid.py 418: Cleaning provisional download folders for 2018 2019-01-28 03:03:17 DEBUG folderspreview.py 367: Cleaning subfolders created for scan id 3 2019-01-28 03:03:17 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:03:18 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:18 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:18 DEBUG proximity.py 1989: Updating Timeline state from generated to empty 2019-01-28 03:03:18 DEBUG devices.py 507: -- Device Collection -- 2019-01-28 03:03:18 DEBUG devices.py 511: 0 devices: 0 volumes/cameras (0 cameras), 0 this computer 2019-01-28 03:03:18 DEBUG devices.py 515: Device states: 2019-01-28 03:03:18 DEBUG devices.py 520: No devices scanning 2019-01-28 03:03:18 DEBUG devices.py 527: No devices downloading 2019-01-28 03:03:18 DEBUG devices.py 534: No devices thumbnailing 2019-01-28 03:03:18 DEBUG thumbnaildisplay.py 240: -- Thumbnail Model -- 2019-01-28 03:03:18 DEBUG thumbnaildisplay.py 250: 0 thumbnails (0 marked) 2019-01-28 03:03:18 DEBUG thumbnaildisplay.py 255: 0 not downloaded; 0 downloaded; 0 previously downloaded 2019-01-28 03:03:18 DEBUG thumbnaildisplay.py 267: Active devices: (4 removed) 2019-01-28 03:03:18 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:18 DEBUG rapid.py 5416: Using This Computer path /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:03:18 DEBUG rapid.py 4893: Assigning scan id 4 to /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:03:18 DEBUG rpdsql.py 131: INSERT OR REPLACE INTO devices (scan_id, device_name) VALUES (?,?) (4, avendre) 2019-01-28 03:03:18 DEBUG devicedisplay.py 164: Adding /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre to This Computer display with scan id 4 at row 0 2019-01-28 03:03:18 DEBUG devices.py 565: Setting device state for avendre to scanning 2019-01-28 03:03:18 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:18 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:18 DEBUG rapid.py 1611: Setting progress bar to show scanning activity 2019-01-28 03:03:18 DEBUG interprocess.py 192: Started '/usr/bin/python3 /home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py --receive 38113 --send 40797 --controller 35209 --syncclient 34969 --filter 4 --logging 45151' with pid 16929 2019-01-28 03:03:20 DEBUG interprocess.py 1213: Subscribing to logging on port 44065 2019-01-28 03:03:20 DEBUG scan.py 195: Scan 4 worker started 2019-01-28 03:03:20 INFO scan.py 248: Scanning This Computer path avendre 2019-01-28 03:03:20 DEBUG scan.py 1276: Distinguishing approach to timestamp time zones on avendre 2019-01-28 03:03:21 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/SACHSEN-14757-1.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from SACHSEN-14757-1.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from SACHSEN-14757-1.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/ROCO-45045-1.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from ROCO-45045-1.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from ROCO-45045-1.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/MARKLIN-60115a.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from MARKLIN-60115a.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from MARKLIN-60115a.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/ROCO-4386F-3.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from ROCO-4386F-3.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from ROCO-4386F-3.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/ROCO-4281-4262-2.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from ROCO-4281-4262-2.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from ROCO-4281-4262-2.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/ROWA-POP-2.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from ROWA-POP-2.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from ROWA-POP-2.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/Bayer_806_200_0.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from Bayer_806_200_0.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from Bayer_806_200_0.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/ROCO-45045-2.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from ROCO-45045-2.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from ROCO-45045-2.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/Bayer_profi.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from Bayer_profi.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from Bayer_profi.jpg on avendre 2019-01-28 03:03:22 DEBUG scan.py 1243: Examining sample /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/LIMA-309174-1.jpg 2019-01-28 03:03:22 WARNING scan.py 1210: Scanner failed to load metadata from LIMA-309174-1.jpg on avendre 2019-01-28 03:03:22 WARNING scan.py 1222: Scanner failed to extract date time metadata from LIMA-309174-1.jpg on avendre 2019-01-28 03:03:23 ERROR scan.py 699: Sample metadata not extracted from photo SACHSEN-14757-1.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:23 ERROR scan.py 699: Sample metadata not extracted from photo ROCO-45045-1.jpg although it should have been used to determine the device timezone ..... although it should have been used to determine the device timezone 2019-01-28 03:03:38 ERROR scan.py 699: Sample metadata not extracted from photo nexan-R2V-3G6-2.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:38 ERROR scan.py 699: Sample metadata not extracted from photo LOT-TRIPHASE-1.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:38 ERROR scan.py 699: Sample metadata not extracted from photo LOT-TRIPHASE-2.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:38 DEBUG scan.py 886: Sending 50 scanned files from avendre to sink 2019-01-28 03:03:38 DEBUG rpdsql.py 146: Adding 100 rows to db 2019-01-28 03:03:38 DEBUG rpdsql.py 284: SELECT uid, marked FROM files ORDER BY mtime ASC 2019-01-28 03:03:38 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:38 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:38 DEBUG rapid.py 319: Provisional download folders received 2019-01-28 03:03:38 DEBUG rapid.py 326: Provisional download folders change detected 2019-01-28 03:03:38 DEBUG rapid.py 361: Updating file system model and views 2019-01-28 03:03:38 ERROR scan.py 699: Sample metadata not extracted from photo PIKO-FMZ1-b.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:39 ERROR scan.py 699: Sample metadata not extracted from photo Transfo-arnolds-ASS-1.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:39 ERROR scan.py 699: Sample metadata not extracted from photo TITAN-30x110-d.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:39 ERROR scan.py 699: Sample metadata not extracted from photo BUHLER-6735-a.jpg although it should have been used to determine the device timezone ...... 2019-01-28 03:03:51 ERROR scan.py 699: Sample metadata not extracted from photo ROAI-chuchu.jpg although it should have been used to determine the device timezone 2019-01-28 03:03:51 ERROR scan.py 183: Unexpected exception while scanning avendre Traceback (most recent call last): File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py", line 177, in do_work self.do_scan() File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py", line 267, in do_scan self.process_file() File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py", line 705, in process_file file_type File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/scan.py", line 1188, in sample_non_camera_metadata full_file_name=full_file_name, et_process=self.et_process File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/metadatavideo.py", line 101, in __init__ filename=full_file_name, library_file=pymedia_library_file File "/home/vbourdonnec/.local/lib/python3.6/site-packages/pymediainfo/__init__.py", line 219, in parse with open(filename, "rb"): PermissionError: [Errno 13] Permission non accordée: '/var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/Plomberie/lot-raccord.mp4' 2019-01-28 03:03:51 DEBUG scan.py 886: Sending 38 scanned files from avendre to sink 2019-01-28 03:03:51 DEBUG interprocess.py 1222: Unsubscribing to logging on port 44065 2019-01-28 03:03:51 DEBUG interprocess.py 336: Scan Manager currently has no workers 2019-01-28 03:03:51 DEBUG devices.py 565: Setting device state for avendre to idle 2019-01-28 03:03:51 DEBUG rpdsql.py 146: Adding 100 rows to db 2019-01-28 03:03:51 DEBUG rpdsql.py 284: SELECT uid, marked FROM files ORDER BY mtime ASC 2019-01-28 03:03:51 DEBUG rapid.py 1614: Resetting progress bar 2019-01-28 03:03:51 DEBUG devicedisplay.py 348: Setting avendre checkbox to checked 2019-01-28 03:03:51 DEBUG devicedisplay.py 329: -- Device Model for This Computer -- 2019-01-28 03:03:51 DEBUG devicedisplay.py 331: Known devices: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 336: Row 0: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 336: Row 1: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 339: Spinner states: avendre: scanning 2019-01-28 03:03:51 DEBUG devicedisplay.py 341: avendre: checked 2019-01-28 03:03:51 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.photo: 1>] 2019-01-28 03:03:51 DEBUG rpdsql.py 350: SELECT uid FROM files WHERE marked=? AND file_type=? [True, <FileType.video: 2>] 2019-01-28 03:03:51 DEBUG devices.py 507: -- Device Collection -- 2019-01-28 03:03:51 DEBUG devices.py 511: 1 devices: 0 volumes/cameras (0 cameras), 1 this computer 2019-01-28 03:03:51 DEBUG devices.py 515: Device states: avendre: idle 2019-01-28 03:03:51 DEBUG devices.py 520: No devices scanning 2019-01-28 03:03:51 DEBUG devices.py 527: No devices downloading 2019-01-28 03:03:51 DEBUG devices.py 534: No devices thumbnailing 2019-01-28 03:03:51 DEBUG thumbnaildisplay.py 240: -- Thumbnail Model -- 2019-01-28 03:03:51 DEBUG thumbnaildisplay.py 250: 250 thumbnails (250 marked) 2019-01-28 03:03:51 DEBUG thumbnaildisplay.py 255: 250 not downloaded; 0 downloaded; 0 previously downloaded 2019-01-28 03:03:51 DEBUG thumbnaildisplay.py 259: 250 to be generated; 0 generated 2019-01-28 03:03:51 DEBUG thumbnaildisplay.py 267: Active devices: avendre (4 removed) 2019-01-28 03:03:51 DEBUG devicedisplay.py 329: -- Device Model for This Computer -- 2019-01-28 03:03:51 DEBUG devicedisplay.py 331: Known devices: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 336: Row 0: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 336: Row 1: avendre 2019-01-28 03:03:51 DEBUG devicedisplay.py 339: Spinner states: avendre: scanning 2019-01-28 03:03:51 DEBUG devicedisplay.py 341: avendre: checked 2019-01-28 03:03:51 INFO rapid.py 4530: Generating Timeline because a download source has finished being scanned 2019-01-28 03:03:51 DEBUG proximity.py 1989: Updating Timeline state from empty to generating 2019-01-28 03:03:51 DEBUG devices.py 565: Setting device state for avendre to thumbnailing 2019-01-28 03:03:51 DEBUG rapid.py 1605: Setting progress bar maximum to 250 2019-01-28 03:03:51 DEBUG rpdsql.py 480: SELECT uid FROM files WHERE scan_id=? (4, ) 2019-01-28 03:03:52 DEBUG interprocess.py 192: Started '/usr/bin/python3 /home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py --receive 38243 --send 46791 --controller 40533 --syncclient 39079 --filter 4 --logging 45151' with pid 17032 2019-01-28 03:03:52 INFO proximity.py 954: Timeline validation passed 2019-01-28 03:03:52 DEBUG proximity.py 1989: Updating Timeline state from generating to generated 2019-01-28 03:03:52 DEBUG rpdsql.py 474: UPDATE files SET proximity_col1=?, proximity_col2=? WHERE uid=? (250 operations) 2019-01-28 03:03:54 DEBUG interprocess.py 1213: Subscribing to logging on port 35977 2019-01-28 03:03:54 INFO thumbnailpara.py 458: Generating 250 thumbnails for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:03:54 ERROR thumbnailpara.py 449: Exception generating thumbnails for /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre 2019-01-28 03:03:54 ERROR thumbnailpara.py 452: Traceback: Traceback (most recent call last): File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 444, in do_work self.generate_thumbnails() File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 736, in generate_thumbnails task = preprocess_thumbnail_from_disk(rpd_file=rpd_file, processing=processing) File "/home/vbourdonnec/.local/lib/python3.6/site-packages/raphodo/thumbnailpara.py", line 303, in preprocess_thumbnail_from_disk with open(rpd_file.full_file_name, 'rb') as photo: PermissionError: [Errno 13] Permission non accordée: '/var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/avendre/Electricité/osram7w-840.jpg' In short Fresh UBUNTU 18.04, install.py went OK /var/run/user/1000/gvfs/smb-share:server=ntkiller2.local,share=top/home/fbourdonnec/Images/2018 is a readonly samba share mounted on the machine running rpd Scanning ends with an exception. Looks like permissions (read only) on the samba server share are affecting the locally job.