search

google / aiyprojects-raspbian

API libraries, samples, and system images for AIY Projects (Voice Kit and Vision Kit)
https://aiyprojects.withgoogle.com/
Apache License 2.0
1.62k stars 694 forks source link

AIY Vision reports OSError: [Errno 62] Timer expired #382

Open empiimp opened 6 years ago

empiimp commented 6 years ago

When I run ./face_detection_camera.py, after a minute I get this dump and then it exits immediately if I try to run it again with the same erro..

Iteration #3477: num_faces=0
Traceback (most recent call last):
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 137, in transact
    fcntl.ioctl(self._dev, SPICOMM_IOCTL_TRANSACT, buf)
OSError: [Errno 62] Timer expired

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./face_detection_camera.py", line 74, in main
    for i, result in enumerate(inference.run()):
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 76, in run
    yield self._engine.camera_inference()
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 257, in camera_inference
    return self._communicate(request).inference_result
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 187, in _communicate
    response.ParseFromString(self._transport.send(request.SerializeToString()))
  File "/opt/aiy/projects-python/src/aiy/_drivers/_transport.py", line 33, in send
    return self._spicomm.transact(request)
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 147, in transact
    raise SpicommTimeoutError
aiy._drivers._spicomm.SpicommTimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 137, in transact
    fcntl.ioctl(self._dev, SPICOMM_IOCTL_TRANSACT, buf)
OSError: [Errno 62] Timer expired

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./face_detection_camera.py", line 88, in <module>
    main()
  File "./face_detection_camera.py", line 82, in main
    print('Iteration #%d: num_faces=%d' % (i, len(faces)))
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 87, in __exit__
    self.close()
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 79, in close
    self._engine.stop_camera_inference()
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 263, in stop_camera_inference
    self._communicate(request)
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 187, in _communicate
    response.ParseFromString(self._transport.send(request.SerializeToString()))
  File "/opt/aiy/projects-python/src/aiy/_drivers/_transport.py", line 33, in send
    return self._spicomm.transact(request)
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 147, in transact
    raise SpicommTimeoutError
aiy._drivers._spicomm.SpicommTimeoutError

AIY Vision bonnet V1. uname -a Linux raspberrypi 4.14.34+ #1110 Mon Apr 16 14:51:42 BST 2018 armv6l GNU/Linux

dmitriykovalev commented 6 years ago

Could also provide dmesg command output right after this failure?

empiimp commented 6 years ago 
pi@raspberrypi:~/AIY-projects-python/src/examples/vision $ dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.14.34+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 Mon Apr 16 14:51:42 BST 2018
[    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi Zero W Rev 1.1
[    0.000000] Memory policy: Data cache writeback
[    0.000000] cma: Reserved 8 MiB at 0x17400000
[    0.000000] On node 0 totalpages: 98304
[    0.000000] free_area_init_node: node 0, pgdat c09be368, node_mem_map d7c8a000
[    0.000000]   Normal zone: 864 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 98304 pages, LIFO batch:31
[    0.000000] random: fast init done
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 97440
[    0.000000] Kernel command line: 8250.nr_uarts=0 bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:46:77:E3 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=02322b55-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Memory: 370300K/393216K available (6415K kernel code, 587K rwdata, 1984K rodata, 440K init, 677K bss, 14724K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xd8800000 - 0xff800000   ( 624 MB)
                   lowmem  : 0xc0000000 - 0xd8000000   ( 384 MB)
                   modules : 0xbf000000 - 0xc0000000   (  16 MB)
                     .text : 0xc0008000 - 0xc064c188   (6417 kB)
                     .init : 0xc08c8000 - 0xc0936000   ( 440 kB)
                     .data : 0xc0936000 - 0xc09c8d10   ( 588 kB)
                      .bss : 0xc09ce65c - 0xc0a77ba4   ( 678 kB)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] ftrace: allocating 24081 entries in 71 pages
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000028] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000057] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000140] bcm2835: system timer (irq = 27)
[    0.000707] Console: colour dummy device 80x30
[    0.000734] console [tty1] enabled
[    0.000769] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[    0.060292] pid_max: default: 32768 minimum: 301
[    0.060783] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.060801] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.062078] Disabling memory control group subsystem
[    0.062239] CPU: Testing write buffer coherency: ok
[    0.063313] Setting up static identity map for 0x8200 - 0x8238
[    0.064513] devtmpfs: initialized
[    0.074641] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[    0.075019] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.075048] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.076364] pinctrl core: initialized pinctrl subsystem
[    0.077706] NET: Registered protocol family 16
[    0.080768] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.087063] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[    0.087079] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.087197] Serial: AMBA PL011 UART driver
[    0.089933] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[    0.090750] uart-pl011 20201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.129599] bcm2835-dma 20007000.dma: DMA legacy API manager at d880d000, dmachans=0x1
[    0.131934] SCSI subsystem initialized
[    0.132163] usbcore: registered new interface driver usbfs
[    0.132271] usbcore: registered new interface driver hub
[    0.132473] usbcore: registered new device driver usb
[    0.140804] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-04-16 18:21
[    0.142857] clocksource: Switched to clocksource timer
[    0.227980] VFS: Disk quotas dquot_6.6.0
[    0.228102] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.228396] FS-Cache: Loaded
[    0.228717] CacheFiles: Loaded
[    0.245450] NET: Registered protocol family 2
[    0.246622] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    0.246710] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[    0.246804] TCP: Hash tables configured (established 4096 bind 4096)
[    0.246952] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.246982] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.247325] NET: Registered protocol family 1
[    0.248017] RPC: Registered named UNIX socket transport module.
[    0.248028] RPC: Registered udp transport module.
[    0.248033] RPC: Registered tcp transport module.
[    0.248038] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.250028] hw perfevents: no irqs for PMU, sampling events not supported
[    0.250097] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[    0.253894] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[    0.265584] FS-Cache: Netfs 'nfs' registered for caching
[    0.266860] NFS: Registering the id_resolver key type
[    0.266938] Key type id_resolver registered
[    0.266946] Key type id_legacy registered
[    0.266973] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.271488] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.271894] io scheduler noop registered
[    0.271906] io scheduler deadline registered (default)
[    0.272416] io scheduler cfq registered
[    0.272432] io scheduler mq-deadline registered
[    0.272438] io scheduler kyber registered
[    0.274823] BCM2708FB: allocated DMA memory 57500000
[    0.274886] BCM2708FB: allocated DMA channel 0 @ d880d000
[    0.327012] Console: switching to colour frame buffer device 240x67
[    0.370134] bcm2835-rng 20104000.rng: hwrng registered
[    0.370382] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[    0.371610] vc-sm: Videocore shared memory driver
[    0.372278] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[    0.393743] brd: module loaded
[    0.407527] loop: module loaded
[    0.407549] Loading iSCSI transport class v2.0-870.
[    0.408424] usbcore: registered new interface driver smsc95xx
[    0.408461] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.408660] dwc_otg: FIQ enabled
[    0.408669] dwc_otg: NAK holdoff enabled
[    0.408674] dwc_otg: FIQ split-transaction FSM enabled
[    0.408691] Module dwc_common_port init
[    0.409163] usbcore: registered new interface driver usb-storage
[    0.409660] mousedev: PS/2 mouse device common for all mice
[    0.409728] IR NEC protocol handler initialized
[    0.409737] IR RC5(x/sz) protocol handler initialized
[    0.409742] IR RC6 protocol handler initialized
[    0.409749] IR JVC protocol handler initialized
[    0.409754] IR Sony protocol handler initialized
[    0.409759] IR SANYO protocol handler initialized
[    0.409766] IR Sharp protocol handler initialized
[    0.409772] IR MCE Keyboard/mouse protocol handler initialized
[    0.409778] IR XMP protocol handler initialized
[    0.411212] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[    0.411829] bcm2835-cpufreq: min=700000 max=1000000
[    0.412508] sdhci: Secure Digital Host Controller Interface driver
[    0.412521] sdhci: Copyright(c) Pierre Ossman
[    0.413307] mmc-bcm2835 20300000.mmc: could not get clk, deferring probe
[    0.414004] sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe
[    0.414216] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.414815] ledtrig-cpu: registered to indicate activity on CPUs
[    0.414968] hidraw: raw HID events driver (C) Jiri Kosina
[    0.415278] usbcore: registered new interface driver usbhid
[    0.415287] usbhid: USB HID core driver
[    0.416331] vchiq: vchiq_init_state: slot_zero = d7580000, is_master = 0
[    0.418543] [vc_sm_connected_init]: start
[    0.429800] [vc_sm_connected_init]: end - returning 0
[    0.430921] Initializing XFRM netlink socket
[    0.430991] NET: Registered protocol family 17
[    0.431178] Key type dns_resolver registered
[    0.433404] registered taskstats version 1
[    0.442408] uart-pl011 20201000.serial: cts_event_workaround enabled
[    0.442582] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
[    0.446002] mmc-bcm2835 20300000.mmc: mmc_debug:0 mmc_debug2:0
[    0.446023] mmc-bcm2835 20300000.mmc: DMA channel allocated
[    0.504619] sdhost: log_buf @ d7510000 (57510000)
[    0.541334] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    0.543092] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.544782] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.547795] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    0.582937] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    0.584434] of_cfs_init
[    0.584583] of_cfs_init: OK
[    0.585726] Waiting for root device PARTUUID=02322b55-02...
[    0.660940] mmc0: host does not support reading read-only switch, assuming write-enable
[    0.663559] mmc0: new high speed SDHC card at address 59b4
[    0.664554] mmcblk0: mmc0:59b4 GB2MW 29.8 GiB
[    0.667213]  mmcblk0: p1 p2
[    0.683059] mmc1: new high speed SDIO card at address 0001
[    0.690917] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    0.691025] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    0.692818] devtmpfs: mounted
[    0.695656] Freeing unused kernel memory: 440K
[    0.695668] This architecture does not have kernel memory protection.
[    1.258109] systemd[1]: System time before build time, advancing clock.
[    1.454526] NET: Registered protocol family 10
[    1.456915] Segment Routing with IPv6
[    1.485593] ip_tables: (C) 2000-2006 Netfilter Core Team
[    1.527759] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    1.528947] systemd[1]: Detected architecture arm.
[    1.530746] systemd[1]: Set hostname to <raspberrypi>.
[    2.771361] systemd[1]: Configuration file /opt/aiy/io-mcu-firmware/aiy_io_permission.service is marked executable. Please remove executable permission bits. Proceeding anyway.
[    2.913032] systemd[1]: Reached target Swap.
[    2.915255] systemd[1]: Listening on Journal Socket.
[    2.916037] systemd[1]: Listening on fsck to fsckd communication Socket.
[    2.918032] systemd[1]: Created slice User and Session Slice.
[    2.919819] systemd[1]: Created slice System Slice.
[    2.927298] systemd[1]: Starting File System Check on Root Device...
[    3.332068] dwc2 20980000.usb: 20980000.usb supply vusb_d not found, using dummy regulator
[    3.332211] dwc2 20980000.usb: 20980000.usb supply vusb_a not found, using dummy regulator
[    3.793123] dwc2 20980000.usb: EPs: 8, dedicated fifos, 4080 entries in SPRAM
[    3.794189] dwc2 20980000.usb: DWC OTG Controller
[    3.794283] dwc2 20980000.usb: new USB bus registered, assigned bus number 1
[    3.794381] dwc2 20980000.usb: irq 33, io mem 0x20980000
[    3.794886] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    3.794903] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    3.794913] usb usb1: Product: DWC OTG Controller
[    3.794923] usb usb1: Manufacturer: Linux 4.14.34+ dwc2_hsotg
[    3.794934] usb usb1: SerialNumber: 20980000.usb
[    3.796347] hub 1-0:1.0: USB hub found
[    3.796462] hub 1-0:1.0: 1 port detected
[    3.886928] i2c /dev entries driver
[    3.913187] pwm_soft: loading out-of-tree module taints kernel.
[    3.914284] SoftPWM v0.1 initializing.
[    3.914301] Clock resolution is 1ns
[    3.914404] SoftPWM initialized.
[    4.232976] usb 1-1: new low-speed USB device number 2 using dwc2
[    4.492975] usb 1-1: New USB device found, idVendor=05af, idProduct=0408
[    4.493005] usb 1-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0
[    4.493018] usb 1-1: Product: 2.4G USB RF KeyBoard
[    4.534520] input: 2.4G USB RF KeyBoard as /devices/platform/soc/20980000.usb/usb1/1-1/1-1:1.0/0003:05AF:0408.0001/input/input0
[    4.604802] hid-generic 0003:05AF:0408.0001: input,hidraw0: USB HID v1.10 Keyboard [2.4G USB RF KeyBoard] on usb-20980000.usb-1/input0
[    4.638796] input: 2.4G USB RF KeyBoard as /devices/platform/soc/20980000.usb/usb1/1-1/1-1:1.1/0003:05AF:0408.0002/input/input1
[    4.646189] hid-generic 0003:05AF:0408.0002: input,hidraw1: USB HID v1.10 Mouse [2.4G USB RF KeyBoard] on usb-20980000.usb-1/input1
[    4.717128] input: 2.4G USB RF KeyBoard as /devices/platform/soc/20980000.usb/usb1/1-1/1-1:1.2/0003:05AF:0408.0003/input/input2
[    4.784165] hid-generic 0003:05AF:0408.0003: input,hiddev96,hidraw2: USB HID v1.10 Device [2.4G USB RF KeyBoard] on usb-20980000.usb-1/input2
[   12.483217] random: crng init done
[   88.137133] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[   88.536850] systemd-journald[85]: Received request to flush runtime journal from PID 1
[   92.473014] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[   92.493497] brcmfmac: brcmf_fw_map_chip_to_name: using brcm/brcmfmac43430-sdio.bin for chip 0x00a9a6(43430) rev 0x000001
[   92.493974] usbcore: registered new interface driver brcmfmac
[   92.926758] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Oct 23 2017 03:55:53 version 7.45.98.38 (r674442 CY) FWID 01-e58d219f
[   92.928229] brcmfmac: brcmf_c_preinit_dcmds: CLM version = API: 12.2 Data: 7.11.15 Compiler: 1.24.2 ClmImport: 1.24.1 Creation: 2014-05-26 10:53:55 Inc Data: 9.10.39 Inc Compiler: 1.29.4 Inc ClmImport: 1.36.3 Creation: 2017-10-23 03:47:14 
[   96.595110] uart-pl011 20201000.serial: no DMA platform data
[  100.203502] using random self ethernet address
[  100.203526] using random host ethernet address
[  101.365490] Bluetooth: Core ver 2.22
[  101.365706] NET: Registered protocol family 31
[  101.365720] Bluetooth: HCI device and connection manager initialized
[  101.365758] Bluetooth: HCI socket layer initialized
[  101.365785] Bluetooth: L2CAP socket layer initialized
[  101.365861] Bluetooth: SCO socket layer initialized
[  101.476176] Bluetooth: HCI UART driver ver 2.3
[  101.476202] Bluetooth: HCI UART protocol H4 registered
[  101.476209] Bluetooth: HCI UART protocol Three-wire (H5) registered
[  101.493197] Bluetooth: HCI UART protocol Broadcom registered
[  103.752274] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[  103.752289] Bluetooth: BNEP filters: protocol multicast
[  103.752317] Bluetooth: BNEP socket layer initialized
[  104.154235] Bluetooth: RFCOMM TTY layer initialized
[  104.154272] Bluetooth: RFCOMM socket layer initialized
[  104.154310] Bluetooth: RFCOMM ver 1.11
[  104.313976] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[  105.907380] usb0: HOST MAC 6a:75:fa:48:5d:7d
[  105.915559] usb0: MAC a6:7d:f8:91:e7:ff
[  105.915771] dwc2 20980000.usb: bound driver configfs-gadget
[  113.061670] systemd[1]: apt-daily-upgrade.timer: Adding 2min 57.494648s random time.
[  113.197855] aiy-vision spi0.0: Initializing
[  113.324673] aiy-vision spi0.0: Failed to bind reset GPIO
[  113.403392] aiy-vision spi0.0: Initializing
[  113.406974] aiy-vision spi0.0: Failed to bind reset GPIO
[  113.754458] aiy-io-i2c 1-0051: Setting board type vision
[  113.755198] aiy-io-i2c 1-0051: Driver loaded
[  113.755544] aiy-vision spi0.0: Initializing
[  113.773629] aiy-vision spi0.0: Failed to bind reset GPIO
[  116.033808] pwm-aiy-io pwm-aiy-io: Driver loaded
[  116.034108] aiy-vision spi0.0: Initializing
[  116.040670] aiy-vision spi0.0: Failed to bind reset GPIO
[  116.231028] gpio-aiy-io gpio-aiy-io: Driver loaded
[  116.231423] aiy-vision spi0.0: Initializing
[  116.240268] aiy-vision spi0.0: Resetting myriad on probe
[  116.240286] aiy-vision spi0.0: Resetting myriad
[  116.462781] aiy-adc aiy-adc: Vision bonnet ADC configuration.
[  116.496603] aiy-adc aiy-adc: Driver loaded
[  117.773095] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[  117.773117] brcmfmac: power management disabled
[  118.799024] aiy-vision spi0.0: Writing myriad firmware
[  118.978770] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  120.193223] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready
[  123.682095] aiy-vision spi0.0: Myriad booting
[  123.863198] aiy-vision spi0.0: Myriad ready
[  141.152986] fuse init (API version 7.26)
[  890.093959] aiy-vision spi0.0: Incoming crc mismatch: slave c976638d vs computed 56c98728
[ 1566.002983] aiy-vision spi0.0: Transaction timed out
[ 1571.043206] aiy-vision spi0.0: Transaction timed out
pi@raspberrypi:~/AIY-projects-python/src/examples/vision $
dmitriykovalev commented 6 years ago

Something weird is happening, can you try to generate more debug output in the kernel log by running 

modprobe -r aiy-vision && modprobe aiy-vision debug=1

and then python example followed by dmesg?

That command line enables debug mode in the driver, switching back to normal is

modprobe -r aiy-vision && modprobe aiy-vision
empiimp commented 6 years ago

Thank you, Dmitriy, - I had to use sudo to set the debug mode and now I'm getting a missing dev file when I run the face detection:

pi@raspberrypi:~/AIY-projects-python $ modprobe -r aiy-vision && modprobe aiy-vision debug=1
modprobe: ERROR: ../libkmod/libkmod-module.c:793 kmod_module_remove_module() could not remove 'aiy_vision': Operation not permitted
pi@raspberrypi:~/AIY-projects-python $ sudo modprobe -r aiy-vision && sudo modprobe aiy-vision debug=1
pi@raspberrypi:~/AIY-projects-python $ cd src/examples/vision/
pi@raspberrypi:~/AIY-projects-python/src/examples/vision $ ./face_detection_camera.py 
Traceback (most recent call last):
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 91, in __init__
    self._dev = open(SPICOMM_DEV, 'r+b', 0)
FileNotFoundError: [Errno 2] No such file or directory: '/dev/vision_spicomm'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./face_detection_camera.py", line 88, in <module>
    main()
  File "./face_detection_camera.py", line 73, in main
    with CameraInference(face_detection.model()) as inference:
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 67, in __init__
    self._engine = InferenceEngine()
  File "/opt/aiy/projects-python/src/aiy/vision/inference.py", line 164, in __init__
    self._transport = make_transport()
  File "/opt/aiy/projects-python/src/aiy/_drivers/_transport.py", line 89, in make_transport
    return _SpiTransport()
  File "/opt/aiy/projects-python/src/aiy/_drivers/_transport.py", line 29, in __init__
    self._spicomm = _spicomm.Spicomm()
  File "/opt/aiy/projects-python/src/aiy/_drivers/_spicomm.py", line 93, in __init__
    raise SpicommDevNotFoundError
aiy._drivers._spicomm.SpicommDevNotFoundError
dmitriykovalev commented 6 years ago

Something didn't work, missing /dev/vision_spicomm means driver is not loaded properly. You need to use sudo with each command, sorry I missed that. To remove the driver run

sudo modprobe -r aiy-vision

This could fail if driver is not loaded and that's fine. To load driver in debug mode run

sudo modprobe aiy-vision debug=1

and to load in normal mode (after removing)

sudo modprobe aiy-vision

Can you please try again?

empiimp commented 6 years ago

dmesg_20180529.log

Attached.

empiimp commented 6 years ago

Hi Dmitriy - Just checking if you had a chance to look through the attached dmesg file from my last post. After rebooting, it does run the face recognition for a random length of time and once it hits the timeout, any run after that fails immediately. Thank you for the help, Paul...

sainttelant commented 6 years ago

@empiimp ,hi, guy, i got the totally same errors after i ran ./face_detection_camera.py, so how did you get it done

empiimp commented 6 years ago

I unplugged it... I don't know of a solution to the timeout at this point. Did you find a solution?