nischi / MMM-Face-Reco-DNN

Face recognition with opencv and deep neural network
MIT License
90 stars 46 forks source link

Uncaught Exception when starting MM #148

Closed DavidMichailis closed 6 months ago

DavidMichailis commented 6 months ago

Summary: Encountered an uncaught exception while running the MagicMirror application with the MMM-Face-Reco-DNN module.

Description: When starting the MagicMirror application using npm start, the application initializes successfully, but the MMM-Face-Reco-DNN module throws an uncaught exception. The issue seems to be related to OpenCV and the Python script recognition.py within the MMM-Face-Reco-DNN module.

Actual Behavior: After successfully loading various modules, the MMM-Face-Reco-DNN module encounters an uncaught exception related to OpenCV and the recognition.py script. The error suggests a problem with the implementation of the cvWaitKey function and advises rebuilding the OpenCV library with appropriate support.

Environment: MagicMirror Version: 2.25.0 OpenCV Version: 4.7.0 gcc version 10.2.1 20210110 (Raspbian 10.2.1-6+rpi1) pkg-config version 0.29.2-1 python3-dev version 3.9.2-3 libcairo2-dev version 1.16.0-5+rpt1 libgtk2.0-dev version 2.24.33-2+rpt1

Logs/Errors:

[20.12.2023 07:29.52.966] [ERROR] Whoops! There was an uncaught exception...
[20.12.2023 07:29.52.969] [ERROR] PythonShellError: [87:31:07.801352814] [17393] INFO Camera camera_manager.cpp:297 libcamera v0.0.5+83-bde9b04f
...
cv2.error: OpenCV(4.7.0) /tmp/pip-install-x4u7f527/opencv-python_28a07ec5e610418cb27b1cfb0ea204fc/opencv/modules/highgui/src/window.cpp:1338: error: (-2:Unspecified error) The function is not implemented. Rebuild the library with Windows, GTK+ 2.x or Cocoa support. If you are on Ubuntu or Debian, install libgtk2.0-dev and pkg-config, then re-run cmake or configure script in function 'cvWaitKey'
...
[20.12.2023 07:29.52.970] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?

Complete Log:

mirror@magicMirror:~/MagicMirror/opencv/build $ cd ~/MagicMirror
npm start

> magicmirror@2.25.0 start
> DISPLAY="${DISPLAY:=:0}" ./node_modules/.bin/electron js/electron.js

[20.12.2023 07:29.34.441] [LOG]   Starting MagicMirror: v2.25.0
[20.12.2023 07:29.34.450] [LOG]   Loading config ...
[20.12.2023 07:29.34.454] [DEBUG] config template file not exists, no envsubst
[20.12.2023 07:29.34.460] [LOG]   Loading module helpers ...
[20.12.2023 07:29.34.463] [LOG]   No helper found for module: alert.
[20.12.2023 07:29.34.497] [LOG]   Initializing new module helper ...
[20.12.2023 07:29.34.498] [LOG]   Module helper loaded: updatenotification
[20.12.2023 07:29.34.500] [LOG]   No helper found for module: clock.
[20.12.2023 07:29.34.502] [LOG]   No helper found for module: MMM-MonthCalendar.
[20.12.2023 07:29.34.759] [LOG]   Initializing new module helper ...
[20.12.2023 07:29.34.759] [LOG]   Module helper loaded: calendar
[20.12.2023 07:29.34.761] [LOG]   No helper found for module: weather.
[20.12.2023 07:29.34.762] [LOG]   No helper found for module: MMM-WeatherDependentClothes.
[20.12.2023 07:29.35.273] [LOG]   Initializing new module helper ...
[20.12.2023 07:29.35.273] [LOG]   Module helper loaded: MMM-SystemStats
[20.12.2023 07:29.35.359] [LOG]   Initializing new module helper ...
[20.12.2023 07:29.35.359] [LOG]   Module helper loaded: MMM-OnSpotify
[20.12.2023 07:29.35.377] [LOG]   Initializing new module helper ...
[20.12.2023 07:29.35.378] [LOG]   Module helper loaded: MMM-Face-Reco-DNN
[20.12.2023 07:29.35.378] [LOG]   All module helpers loaded.
[20.12.2023 07:29.35.388] [LOG]   Starting server on port 8080 ... 
[20.12.2023 07:29.36.011] [LOG]   Server started ...
[20.12.2023 07:29.36.011] [LOG]   Connecting socket for: updatenotification
[20.12.2023 07:29.36.012] [LOG]   Starting module helper: updatenotification
[20.12.2023 07:29.36.013] [LOG]   Connecting socket for: calendar
[20.12.2023 07:29.36.013] [LOG]   Starting node helper for: calendar
[20.12.2023 07:29.36.014] [LOG]   Connecting socket for: MMM-SystemStats
[20.12.2023 07:29.36.014] [LOG]   Connecting socket for: MMM-OnSpotify
[20.12.2023 07:29.36.015] [LOG]   [Node Helper] Init >> MMM-OnSpotify
[20.12.2023 07:29.36.016] [LOG]   Connecting socket for: MMM-Face-Reco-DNN
[20.12.2023 07:29.36.017] [LOG]   Starting module helper: MMM-Face-Reco-DNN
[20.12.2023 07:29.36.017] [LOG]   Sockets connected & modules started ...
[20.12.2023 07:29.36.192] [LOG]   Launching application.
[17310:1220/072936.694034:ERROR:object_proxy.cc(590)] Failed to call method: org.freedesktop.portal.Settings.Read: object_path= /org/freedesktop/portal/desktop: org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.portal.Desktop was not provided by any .service files
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to open kms_swrast: /usr/lib/dri/kms_swrast_dri.so: cannot open shared object file: Permission denied (search paths /usr/lib/arm-linux-gnueabihf/dri:\$${ORIGIN}/dri:/usr/lib/dri)
failed to load driver: kms_swrast
MESA-LOADER: failed to open swrast: /usr/lib/dri/swrast_dri.so: cannot open shared object file: Permission denied (search paths /usr/lib/arm-linux-gnueabihf/dri:\$${ORIGIN}/dri:/usr/lib/dri)
failed to load swrast driver
[20.12.2023 07:29.41.408] [LOG]   Create new calendarfetcher for url: https://calendar.google.com/calendar/ical/_{myCalendarInformation}_/basic.ics - Interval: 3600000
[20.12.2023 07:29.41.745] [INFO]  Checking git for module: MMM-MonthCalendar
[20.12.2023 07:29.41.894] [INFO]  Checking git for module: MMM-WeatherDependentClothes
[20.12.2023 07:29.41.962] [INFO]  Checking git for module: MMM-SystemStats
[20.12.2023 07:29.42.030] [INFO]  Checking git for module: MMM-OnSpotify
[20.12.2023 07:29.42.154] [INFO]  Checking git for module: MMM-Face-Reco-DNN
[20.12.2023 07:29.42.376] [INFO]  Checking git for module: MagicMirror
[20.12.2023 07:29.44.405] [INFO]  Calendar-Fetcher: Broadcasting 55 events from https://calendar.google.com/calendar/ical/_{myCalendarInformation}_/basic.ics.
[20.12.2023 07:29.51.240] [LOG]   [MMM-Face-Reco-DNN] loading encodings + face detector...
[20.12.2023 07:29.51.327] [LOG]   [MMM-Face-Reco-DNN] starting video stream...
[20.12.2023 07:29.51.327] [LOG]   [MMM-Face-Reco-DNN] 1920,1080
[20.12.2023 07:29.51.328] [LOG]   [MMM-Face-Reco-DNN] 500
[20.12.2023 07:29.52.966] [ERROR] Whoops! There was an uncaught exception...
[20.12.2023 07:29.52.969] [ERROR] PythonShellError: [87:31:07.801352814] [17393]  INFO Camera camera_manager.cpp:297 libcamera v0.0.5+83-bde9b04f
[87:31:07.854357191] [17488]  INFO RPI vc4.cpp:437 Registered camera /base/soc/i2c0mux/i2c@1/ov5647@36 to Unicam device /dev/media4 and ISP device /dev/media1
[87:31:07.854450967] [17488]  INFO RPI pipeline_base.cpp:1101 Using configuration file '/usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml'
[87:31:07.862814700] [17393]  INFO Camera camera.cpp:1033 configuring streams: (0) 1920x1080-XRGB8888 (1) 1920x1080-SGBRG10_CSI2P
[87:31:07.863480302] [17488]  INFO RPI vc4.cpp:565 Sensor: /base/soc/i2c0mux/i2c@1/ov5647@36 - Selected sensor format: 1920x1080-SGBRG10_1X10 - Selected unicam format: 1920x1080-pGAA
Traceback (most recent call last):
  File "/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/tools/recognition.py", line 183, in <module>
    key = cv2.waitKey(1) & 0xFF
cv2.error: OpenCV(4.7.0) /tmp/pip-install-x4u7f527/opencv-python_28a07ec5e610418cb27b1cfb0ea204fc/opencv/modules/highgui/src/window.cpp:1338: error: (-2:Unspecified error) The function is not implemented. Rebuild the library with Windows, GTK+ 2.x or Cocoa support. If you are on Ubuntu or Debian, install libgtk2.0-dev and pkg-config, then re-run cmake or configure script in function 'cvWaitKey'

    at PythonShell.parseError (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:311:21)
    at terminateIfNeeded (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:193:32)
    at ChildProcess.<anonymous> (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:185:13)
    at ChildProcess.emit (node:events:513:28)
    at Process.onexit (node:internal/child_process:291:12) {
  executable: 'python3',
  options: null,
  script: 'modules/MMM-Face-Reco-DNN/tools/recognition.py',
  args: [
    '--cascade=modules/MMM-Face-Reco-DNN/model/haarcascade_frontalface_default.xml',
    '--encodings=modules/MMM-Face-Reco-DNN/model/encodings.pickle',
    '--rotateCamera=1',
    '--method=dnn',
    '--detectionMethod=hog',
    '--interval=2000',
    '--output=0',
    '--outputmm=1',
    '--extendDataset=False',
    '--dataset=modules/MMM-Face-Reco-DNN/dataset/',
    '--tolerance=0.6',
    '--brightness=0',
    '--contrast=0',
    '--resolution=1920,1080',
    '--processWidth=500'
  ],
  exitCode: 1
}
[20.12.2023 07:29.52.970] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?
[20.12.2023 07:29.52.970] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues
^C/home/mirror/MagicMirror/node_modules/electron/dist/electron exited with signal SIGINT

Additional Information: I reinstalled cmake twice in an attempt to resolve the issue.

Behavior Analysis:

nischi commented 6 months ago

hi @DavidMichailis Thank you for the detailed error message. Is it possible that you only installed opencv-python-headless instead of opencv-python? We had the issue that waitKey is not available with opencv-python-headless.

DavidMichailis commented 6 months ago

Thank you for your prompt response. It's highly probable that I indeed installed opencv-python-headless, given that I began this project some time ago. I appreciate your suggestion, and I will thoroughly examine my installed packages. If opencv-python-headless is detected, I'll proceed to uninstall it and replace it with opencv-python. I'll provide an update later tonight once I've made these adjustments. Thanks again for your assistance!

DavidMichailis commented 6 months ago

I have now checked and realized that I had installed opencv-python. See:

mirror@magicMirror:~/MagicMirror $ pip show opencv-python
Name: opencv-python
Version: 4.7.0.72
Summary: Wrapper package for OpenCV python bindings.
Home-page: https://github.com/opencv/opencv-python
Author: 
Author-email: 
License: Apache 2.0
Location: /home/mirror/.local/lib/python3.9/site-packages
Requires: numpy, numpy, numpy, numpy
Required-by: 
mirror@magicMirror:~/MagicMirror $ pip show opencv-python-headless
WARNING: Package(s) not found: opencv-python-headless

To be on the safe side i uninstalled and reinstalled opencv. i couldn't see any changes except for a version update.

mirror@magicMirror:~/MagicMirror $ pip show opencv-python
Name: opencv-python
Version: 4.8.1.78
Summary: Wrapper package for OpenCV python bindings.
Home-page: https://github.com/opencv/opencv-python
Author: 
Author-email: 
License: Apache 2.0
Location: /home/mirror/.local/lib/python3.9/site-packages
Requires: numpy, numpy, numpy, numpy
Required-by: 

Apparently the waitKey error is now gone... but I have a new error that I unfortunately cannot explain...

mirror@magicMirror:~/MagicMirror $ npm start

> magicmirror@2.25.0 start
> DISPLAY="${DISPLAY:=:0}" ./node_modules/.bin/electron js/electron.js

[20.12.2023 23:12.48.686] [LOG]   Starting MagicMirror: v2.25.0
[20.12.2023 23:12.48.692] [LOG]   Loading config ...
[20.12.2023 23:12.48.695] [DEBUG] config template file not exists, no envsubst
[20.12.2023 23:12.48.701] [LOG]   Loading module helpers ...
[20.12.2023 23:12.48.703] [LOG]   No helper found for module: alert.
[20.12.2023 23:12.48.738] [LOG]   Initializing new module helper ...
[20.12.2023 23:12.48.739] [LOG]   Module helper loaded: updatenotification
[20.12.2023 23:12.48.741] [LOG]   No helper found for module: clock.
[20.12.2023 23:12.48.741] [LOG]   No helper found for module: MMM-MonthCalendar.
[20.12.2023 23:12.48.978] [LOG]   Initializing new module helper ...
[20.12.2023 23:12.48.978] [LOG]   Module helper loaded: calendar
[20.12.2023 23:12.48.979] [LOG]   No helper found for module: weather.
[20.12.2023 23:12.48.980] [LOG]   No helper found for module: MMM-WeatherDependentClothes.
[20.12.2023 23:12.49.466] [LOG]   Initializing new module helper ...
[20.12.2023 23:12.49.466] [LOG]   Module helper loaded: MMM-SystemStats
[20.12.2023 23:12.49.550] [LOG]   Initializing new module helper ...
[20.12.2023 23:12.49.550] [LOG]   Module helper loaded: MMM-OnSpotify
[20.12.2023 23:12.49.563] [LOG]   Initializing new module helper ...
[20.12.2023 23:12.49.564] [LOG]   Module helper loaded: MMM-Face-Reco-DNN
[20.12.2023 23:12.49.564] [LOG]   All module helpers loaded.
[20.12.2023 23:12.49.575] [LOG]   Starting server on port 8080 ... 
[20.12.2023 23:12.49.850] [LOG]   Server started ...
[20.12.2023 23:12.49.854] [LOG]   Connecting socket for: updatenotification
[20.12.2023 23:12.49.855] [LOG]   Starting module helper: updatenotification
[20.12.2023 23:12.49.855] [LOG]   Connecting socket for: calendar
[20.12.2023 23:12.49.856] [LOG]   Starting node helper for: calendar
[20.12.2023 23:12.49.857] [LOG]   Connecting socket for: MMM-SystemStats
[20.12.2023 23:12.49.857] [LOG]   Connecting socket for: MMM-OnSpotify
[20.12.2023 23:12.49.859] [LOG]   [Node Helper] Init >> MMM-OnSpotify
[20.12.2023 23:12.49.860] [LOG]   Connecting socket for: MMM-Face-Reco-DNN
[20.12.2023 23:12.49.860] [LOG]   Starting module helper: MMM-Face-Reco-DNN
[20.12.2023 23:12.49.861] [LOG]   Sockets connected & modules started ...
[20.12.2023 23:12.49.907] [LOG]   Launching application.
[23199:1220/231250.046846:ERROR:object_proxy.cc(590)] Failed to call method: org.freedesktop.portal.Settings.Read: object_path= /org/freedesktop/portal/desktop: org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.portal.Desktop was not provided by any .service files
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to retrieve device information
MESA-LOADER: failed to open kms_swrast: /usr/lib/dri/kms_swrast_dri.so: cannot open shared object file: Permission denied (search paths /usr/lib/arm-linux-gnueabihf/dri:\$${ORIGIN}/dri:/usr/lib/dri)
failed to load driver: kms_swrast
MESA-LOADER: failed to open swrast: /usr/lib/dri/swrast_dri.so: cannot open shared object file: Permission denied (search paths /usr/lib/arm-linux-gnueabihf/dri:\$${ORIGIN}/dri:/usr/lib/dri)
failed to load swrast driver
[20.12.2023 23:12.53.330] [LOG]   Create new calendarfetcher for url: https://calendar.google.com/calendar/ical/_{myCalendarInformation}_/basic.ics - Interval: 3600000
[20.12.2023 23:12.53.665] [INFO]  Checking git for module: MMM-MonthCalendar
[20.12.2023 23:12.53.712] [INFO]  Checking git for module: MMM-WeatherDependentClothes
[20.12.2023 23:12.53.773] [INFO]  Checking git for module: MMM-SystemStats
[20.12.2023 23:12.53.828] [INFO]  Checking git for module: MMM-OnSpotify
[20.12.2023 23:12.53.898] [INFO]  Checking git for module: MMM-Face-Reco-DNN
[20.12.2023 23:12.53.955] [INFO]  Checking git for module: MagicMirror
[20.12.2023 23:12.55.684] [INFO]  Calendar-Fetcher: Broadcasting 55 events from https://calendar.google.com/calendar/ical/_{myCalendarInformation}_/basic.ics.
[20.12.2023 23:13.01.909] [ERROR] Whoops! There was an uncaught exception...
[20.12.2023 23:13.01.911] [ERROR] PythonShellError: ImportError: /home/mirror/.local/lib/python3.9/site-packages/cv2/cv2.abi3.so: undefined symbol: __atomic_store_8
    at PythonShell.parseError (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:303:21)
    at terminateIfNeeded (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:193:32)
    at ChildProcess.<anonymous> (/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/node_modules/python-shell/index.js:185:13)
    at ChildProcess.emit (node:events:513:28)
    at Process.onexit (node:internal/child_process:291:12)
    ----- Python Traceback -----
    File "/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/tools/recognition.py", line 4, in <module>
      import cv2
    File "/home/mirror/.local/lib/python3.9/site-packages/cv2/__init__.py", line 181, in <module>
      bootstrap()
    File "/home/mirror/.local/lib/python3.9/site-packages/cv2/__init__.py", line 153, in bootstrap
      native_module = importlib.import_module("cv2")
    File "/usr/lib/python3.9/importlib/__init__.py", line 127, in import_module
      return _bootstrap._gcd_import(name[level:], package, level) {
  traceback: 'Traceback (most recent call last):\n' +
    '  File "/home/mirror/MagicMirror/modules/MMM-Face-Reco-DNN/tools/recognition.py", line 4, in <module>\n' +
    '    import cv2\n' +
    '  File "/home/mirror/.local/lib/python3.9/site-packages/cv2/__init__.py", line 181, in <module>\n' +
    '    bootstrap()\n' +
    '  File "/home/mirror/.local/lib/python3.9/site-packages/cv2/__init__.py", line 153, in bootstrap\n' +
    '    native_module = importlib.import_module("cv2")\n' +
    '  File "/usr/lib/python3.9/importlib/__init__.py", line 127, in import_module\n' +
    '    return _bootstrap._gcd_import(name[level:], package, level)\n' +
    'ImportError: /home/mirror/.local/lib/python3.9/site-packages/cv2/cv2.abi3.so: undefined symbol: __atomic_store_8\n',
  executable: 'python3',
  options: null,
  script: 'modules/MMM-Face-Reco-DNN/tools/recognition.py',
  args: [
    '--cascade=modules/MMM-Face-Reco-DNN/model/haarcascade_frontalface_default.xml',
    '--encodings=modules/MMM-Face-Reco-DNN/model/encodings.pickle',
    '--rotateCamera=1',
    '--method=dnn',
    '--detectionMethod=hog',
    '--interval=2000',
    '--output=0',
    '--outputmm=1',
    '--extendDataset=False',
    '--dataset=modules/MMM-Face-Reco-DNN/dataset/',
    '--tolerance=0.6',
    '--brightness=0',
    '--contrast=0',
    '--resolution=1920,1080',
    '--processWidth=500'
  ],
  exitCode: 1
}
[20.12.2023 23:13.01.913] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?
[20.12.2023 23:13.01.913] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues
nischi commented 6 months ago

But this looks now like he is not finding open-cv at all. he cant import it.

can you open a python shell and try to import cv2?

python
import cv2
DavidMichailis commented 6 months ago

Sorry for the late reply. Import CV2 did not work either. I then decided to completely reset the RaspBi. Now it works. Thanks for your help!