motioneye icon indicating copy to clipboard operation
motioneye copied to clipboard

Webhook not being executed

Open lowlyocean opened this issue 3 years ago • 10 comments

Hello, I'm seeing the log of motioneye mentions the webhook I've configured as part of on_event_start (of course <publicdomain.com> is some real domain):

on_event_start /usr/local/lib/python2.7/dist-packages/motioneye/scripts/relayevent.sh "/etc/motioneye/motioneye.conf" start %t; /usr/bin/python /usr/local/lib/python2.7/dist-packages/motioneye/meyectl.pyc webhook -c /etc/motioneye/motioneye.conf 'POSTf' 'https://<publicdomain.com>/sub-url/motioneye'

However, I see no hits in the log for [webhook] and in fact it looks like that meyectl.pyc webhook is never being launched. The log does indicate that there are motion detection events and that the relayevent.sh is being executed:

DEBUG: received relayed event start for motion camera id

lowlyocean avatar Aug 02 '22 02:08 lowlyocean

Please try whether this works with the dev branch version, which contains a lot of fixes, aside of moving to Python 3: https://github.com/motioneye-project/motioneye/tree/dev#installation

MichaIng avatar Aug 17 '22 18:08 MichaIng

Thanks @MichaIng I can give it a try to see if that helps. Any tips to preserve configuration of both motion and motioneye in going from default branch (python2) to dev? Also, do you think the dev branch should become the default for this project, to avoid others from encountering similar misunderstanding?

lowlyocean avatar Aug 17 '22 18:08 lowlyocean

Also, do you think the dev branch should become the default for this project, to avoid others from encountering similar misunderstanding?

Definitely. There is actually only a single PR I wanted to see merged first: #2462 Also recent motion contains some fixes, so we should support it. However, new full-time job limited my space time to have a look into how it can be finished quickly.

Any tips to preserve configuration of both motion and motioneye in going from default branch (python2) to dev?

Config files should be migrated smoothly without settings being lost. Of course you can do a backup of /etc/motioneye.

MichaIng avatar Aug 17 '22 19:08 MichaIng

I was able to setup dev branch. The problem is still present with this branch. I noticed this branch allows to call webhook after the event ends, but even this does not work. Please let me know if I can offer more detail

lowlyocean avatar Aug 18 '22 03:08 lowlyocean

Can you share the errors you see or logged in:

journalctl -u motioneye

MichaIng avatar Aug 18 '22 18:08 MichaIng

I've set Debug logging and this is what I see logged at the time the motion capture event ends:

Aug 18 14:36:35 www.myrealdomain.com motion[26659]: [4:ml4:Cam1] [DBG] [NET] netcam_output_message: Corrupt JPEG data: 1 extraneous bytes before marker 0xd9
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcam_check_content_type: Content-type image/jpeg
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcam_check_content_length: Content-Length -1
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcam_check_content_length: Content-Length 20224
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcam_read_next_header: Found image header record
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:ml4:Cam1] [DBG] [NET] netcam_proc_jpeg: processing jpeg image - content length 20224
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:ml4:Cam1] [DBG] [EVT] exec_command: Executing external command '/usr/local/lib/python3.7/dist-packages/motioneye/scripts/relayevent.sh "/etc/motioneye/motioneye.conf" stop 4; /usr/bin/python3 /usr/local/lib/python3.7/dist-packages/motioneye/meyectl.py webhook -c /etc/motioneye/motioneye.conf 'POSTf' 'https://myrealdomain.com/my-sub-url/motioneye''
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:ml4:Cam1] [DBG] [EVT] exec_command: Executing external command '/usr/local/lib/python3.7/dist-packages/motioneye/scripts/relayevent.sh "/etc/motioneye/motioneye.conf" movie_end 4 /var/lib/motioneye/Cam1/2022-08-18/14-35-59.mp4'
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:ml4:Cam1] [NTC] [ALL] mlp_actions: End of event 1
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: received relayed event movie_end for motion camera id 4 (camera id 4)
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: adding task "make_movie_preview(/var/lib/motioneye/Cam1/2022-08-18/14-35-59.mp4)" in 5 seconds
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: saving tasks to "/etc/motioneye/tasks.pickle"...
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: 200 POST /_relay_event/?_username=admin&event=movie_end&motion_camera_id=4&_signature=3cdd9900361e128c69813f42bfdc0ae680459cac (127.0.0.1) 7.55ms
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: received relayed event stop for motion camera id 4 (camera id 4)
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: clearing motion detected for camera with id 4
Aug 18 14:36:36 www.myrealdomain.com meyectl[26389]:    DEBUG: 200 POST /_relay_event/?_username=admin&event=stop&motion_camera_id=4&_signature=2606d41e1bca31254be6ad722d8dfa18cf615fa3 (127.0.0.1) 9.83ms
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcam_check_content_type: Content-type image/jpeg
Aug 18 14:36:36 www.myrealdomain.com motion[26659]: [4:nc5:Cam1] [DBG] [NET] netcm_check_content_length: Content-Length -1

lowlyocean avatar Aug 18 '22 18:08 lowlyocean

The webhook event is triggered, the related relayevent.sh call done and the internal POST request succeeds, but I don't see whether the POST request to the external webhook server is done and succeeds. I need to look into the scripts to see what is done and if/where output is expected.

MichaIng avatar Aug 18 '22 19:08 MichaIng

Thanks @MichaIng, please let me know if there's anything else I can provide to help with the troubleshooting

lowlyocean avatar Aug 20 '22 16:08 lowlyocean

It turns out that even with debug level logging, not everything gets logged to journalctl. Instead, I found the culprit only by checking motion.log. It turns out the server was responding with 403 Forbidden. Apparently no User-Agent and Accept headers are defined here which causes the problem.

Would be great for journalctl to include the response to the webhook call when log level = debug. Also it seems the webhook request should include some sensible Accept and User-Agent headers (or let you provide your own). It's also not very obvious from the UI that in order to send form POST, that you provide the fields using query strings (usually only leveraged for a GET)

lowlyocean avatar Sep 10 '22 15:09 lowlyocean

@zagrim @MichaIng mind reviewing above PR I created to introduce ability for users to configure webhook headers from the UI?

lowlyocean avatar Sep 20 '22 00:09 lowlyocean