Pending Auth

[mike-lloyd03]

The version of zmNinja you are reporting:

v1.6.007

The version and OS of ZoneMinder you are using:

Zoneminder 1.34.23
Arch 5.11.2

Platform zmNinja is running on

- iPhone XS, iOS 14.2
- Manjaro 

Did you build the package from source code yourself?
Yes. Installed from Arch AUR with yay

Describe the bug
Not really a bug but I don't know where else to ask this. When setting up the event server, checking System Status in zmNinja, the event server just says "Pending Auth" and I'm not really clear what this means. I've read through the install and key principles sections of the zmeventnotification documentation. I've searched through the zmNinja logs as well and can't find any reference for what "Pending Auth" is telling me. Is there some other level of authentication I need to do?

I have created a user within ZM which has full edit access to all monitors and API enabled. I have entered this username and password in secrets.ini. I'm not sure what else needs to be done to get this working. Thanks for your time.

Debug logs
/var/log/zoneminder/zmeventnotification.log:

02/28/21 14:39:16.852179 zmeventnotification[180283].INF [main:1004] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
02/28/21 14:39:16.864562 zmeventnotification[180283].INF [main:1004] [PARENT: using secrets file: /etc/zm/secrets.ini]
02/28/21 14:39:16.989156 zmeventnotification[180283].INF [main:1004] [PARENT: Push enabled via FCM]
02/28/21 14:39:16.993622 zmeventnotification[180283].INF [main:1004] [PARENT: MQTT Disabled]
02/28/21 14:39:16.996975 zmeventnotification[180283].INF [main:1004] [PARENT: |------- Starting ES version: 6.1.12 ---------|]
02/28/21 14:39:17.134701 zmeventnotification[180283].WAR [main:1012] [PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted]
02/28/21 14:39:17.138328 zmeventnotification[180283].INF [main:1004] [PARENT: Event Notification daemon v 6.1.12 starting]
02/28/21 14:39:17.142357 zmeventnotification[180283].INF [main:1004] [PARENT: Re-loading monitors]
02/28/21 14:39:17.148302 zmeventnotification[180283].INF [main:1004] [PARENT: Secure WS is disabled...]
02/28/21 14:39:17.151628 zmeventnotification[180283].INF [main:1004] [PARENT: Web Socket Event Server listening on port 9000]

/usr/bin/zmeventnotification.pl --check-config:

Configuration (read /etc/zm/zmeventnotification.ini):

Secrets file.......................... /etc/zm/secrets.ini
Base data path........................ /var/lib/zmeventnotification
Restart interval (secs)............... (undefined)

Use admin interface .................. no
Admin interface password.............. (undefined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat

Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 300
Skipped monitors...................... (undefined)

Auth enabled ......................... yes
Auth timeout ......................... 20

Use API Push.......................... no
API Push Script....................... (undefined)

Use FCM .............................. yes
Use FCM V1 APIs....................... yes
FCM Date Format....................... %I:%M %p, %d-%b
Only show latest FCMv1 message........ no
Android FCM push priority............. default

Token file ........................... /var/lib/zmeventnotification/push/tokens.txt

Use MQTT ............................. no
MQTT Server .......................... 127.0.0.1
MQTT Topic ........................... zoneminder
MQTT Username ........................ (undefined)
MQTT Password ........................ (undefined)
MQTT Retain .......................... no
MQTT Tick Interval ................... 15
MQTT TLS CA ........................ (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ........................ (undefined)
MQTT TLS Insecure ........................ no

SSL enabled .......................... no
SSL cert file ........................ /etc/zm/ssl/zoneminder.crt
SSL key file ......................... /etc/zm/ssl/zoneminder.key

Verbose .............................. no
ES Debug level.........................4
Read alarm cause ..................... yes
Tag alarm event id ................... yes
Use custom notification sound ........ no
Send event start notification..........yes
Send event end notification............yes
Monitor rules JSON file................(undefined)

Use Hooks............................. no
Hook Script on Event Start ........... '/var/lib/zmeventnotification/bin/zm_event_start.sh'
User Script on Event Start.............(undefined)
Hook Script on Event End.............. (undefined)
User Script on Event End.............(undefined)
Hook Skipped monitors................. (undefined)

Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... none
Notify on Event End (hook success).... fcm,web,api
Notify on Event End (hook fail)....... none
Notify End only if Start success...... yes

Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM......................yes

Picture URL .......................... http://localhost:8095/index.php?view=image&eid=EVENTID&fid=objdetect&width=600
Include picture....................... yes
Picture username ..................... zmES
Picture password ..................... (defined)

zmNinja log (grepped for 'EvenSever')

Feb 28, 2021 01:42:47:946 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 01:42:47:946 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 01:42:47:946 PM INFO EventSever: Setting up push registration
Feb 28, 2021 01:42:48:003 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)
Feb 28, 2021 01:53:28:810 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 01:55:27:324 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 01:55:27:325 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 01:55:27:325 PM INFO EventSever: Setting up push registration
Feb 28, 2021 01:55:27:369 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)
Feb 28, 2021 01:55:38:421 PM DEBUG EventSever: sendMessage: received->{"event":"push","data":{"type":"badge","badge":0,"appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 01:55:38:422 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 01:59:00:534 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 01:59:00:535 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 01:59:00:535 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 01:59:00:535 PM INFO EventSever: Setting up push registration
Feb 28, 2021 01:59:00:636 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)
Feb 28, 2021 01:59:00:636 PM DEBUG EventSever: sendMessage: received->{"event":"control","data":{"type":"filter","monlist":"1,3,4","intlist":"0,0,0","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 01:59:00:636 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 01:59:00:637 PM DEBUG EventSever: sendMessage: received->{"event":"push","data":{"type":"token","platform":"ios","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","state":"enabled","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 01:59:00:637 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 02:00:04:796 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:04:39:822 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:04:39:822 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:04:39:822 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:04:39:881 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:07:39:887 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:07:44:879 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:07:44:879 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:07:44:879 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:07:44:932 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:11:16:585 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:24:07:204 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:24:07:205 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:24:07:205 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:24:07:206 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:24:07:249 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:24:07:254 PM DEBUG EventSever: sendMessage: received->{"event":"control","data":{"type":"filter","monlist":"1,3,4","intlist":"0,0,0","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 02:24:07:254 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 02:24:07:263 PM DEBUG EventSever: sendMessage: received->{"event":"push","data":{"type":"token","platform":"ios","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","state":"enabled","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 02:24:07:267 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 02:24:07:381 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:24:07:382 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:24:07:382 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:24:07:436 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:24:16:158 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:24:16:158 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:24:16:159 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:24:16:159 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:24:16:182 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:24:16:184 PM DEBUG EventSever: sendMessage: received->{"event":"control","data":{"type":"filter","monlist":"1,3,4","intlist":"0,0,0","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 02:24:16:184 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 02:24:16:184 PM DEBUG EventSever: sendMessage: received->{"event":"push","data":{"type":"token","platform":"ios","token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F","state":"enabled","appversion":"1.6.007"},"token":"f81ik6eawU7is5ui22e2Rc:APA91bEYluSbdxiGbUk6BjDWSD562r-VJVctdN1YxUo42gbo3iPPPk1jgy6DnKV57aESiWd4o5m2mmIWJMdYYldEfAwz0Am3Ju9P33dBHKyKjphUyhhuImrUJOhSmRrgno3PIKAlac9F"}
Feb 28, 2021 02:24:16:184 PM DEBUG EventSever: not initalized, not sending message
Feb 28, 2021 02:26:10:086 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:27:25:060 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:27:25:060 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:27:25:060 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:27:25:079 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:27:39:676 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:34:14:801 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:34:14:801 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:34:14:802 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:34:14:875 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:34:20:529 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:34:20:835 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:34:20:835 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:34:20:836 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:34:20:875 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:34:24:292 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:34:24:292 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:34:24:292 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:34:24:361 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. Connection refused
Feb 28, 2021 02:35:28:151 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:39:45:745 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:41:57:212 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:41:57:212 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:41:57:212 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:41:57:248 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)
Feb 28, 2021 02:42:03:889 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:42:29:382 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:42:29:382 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:42:29:382 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:42:29:407 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)
Feb 28, 2021 02:42:30:637 PM INFO EventSever: Clearing error/close cbk, disconnecting and deleting Event Server socket...
Feb 28, 2021 02:42:47:761 PM INFO EventSever: Initializing Websocket with URL wss://192.168.0.101:9000
Feb 28, 2021 02:42:47:761 PM DEBUG EventSever: Using native websockets...
Feb 28, 2021 02:42:47:763 PM INFO EventSever: Setting up push registration
Feb 28, 2021 02:42:47:842 PM DEBUG EventSever: Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)

Unreleated: is EventSever a typo? Should that be EventServer?

[welcome]

👋 Thanks for opening your first issue here! If you're reporting a 🐞 bug, please make sure you follow the issue template or I may not respond.

[pliablepixels]

Sorry about that. Please ignore. This only works with 1.35 - not supported in 1.34

[mike-lloyd03]

I'm still a bit confused. Isn't 1.34.23 the latest release? And are you saying zmeventsnotification won't work on 1.34 or just the System Status feature in zmNinja?

[pliablepixels]

The ES will work. Just ignore that pending auth status. It relies on a new API that is part of 1.35 (currently master) that is not yet released.

[mike-lloyd03]

Okay great thanks for clarifying. So it seems like zmNinja can't talk to my ES. This line in the logs is probably the source but I'm not sure what it's telling me:

Failed to connect to WebSocket: code: 1006, reason: undefined, exception: The operation couldn’t be completed. (OSStatus error -9806.)

The ES is running at 192.168.0.101:9000 according to netstat so something is working. The zmeventnotification.log doesn't seem to show anything concerning. When I initially started the server, I got an error that tokens.txt was not writable so I fixed the permissions and the error went away but tokens.txt is still just an empty object.

[mike-lloyd03]

Whelp nevermind. Seems SSL is not optional for notifications. I enabled notifications and generated certs per the docs and now it seems to be working. Thanks so much!

I'm gonna play around with getting the ML hooks working later so we'll see how that goes but I at least have notifications which is what I really needed.

[pliablepixels]

I stand corrected, I re-looked at the code.
"Pending Auth" usually means your zmNinja app can't reach the ES. Note that this does not mean notifications won't work, because once the device token is passed onto the ES, it is strictly not necessary for zmNinja to reach the ES. However, you may want to investigate why this is so. The downside is when the device token (required for push) changes, the app won't be able to update the ES and you won't get notifications.

There is a "refresh" icon next to that status, that lets you restart the ES. This operation is only supported in ZM 1.35

[mike-lloyd03]

The issue was that I hadn't set up an ssl cert so my device token wasn't being sent to zmNinja. Following the notes in the .conf file got me up and running. Thanks for your help!