search

scudre / alarm-central-station-receiver

Python daemon for receiving events from a home alarm system via Contact ID protocol
Apache License 2.0
36 stars 10 forks source link

Intermittently working line failure? #52

Open alexp789 opened 5 years ago

alexp789 commented 5 years ago

Hi scudre, firstly thanks for releasing this project, its really really useful. I'm having issues with the alarm integration intermittently working with a Pyronix Enforcer alarm system.

Symptoms: Sometimes (seemingly randomly) it will work fine, all codes are received and decoded as expected:

(venv3) pi@raspberrypi:~ $ sudo /home/pi/venv3/bin/alarmd --no-fork --debug
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.front.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM front
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround40.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround40
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround41
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround50
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround51
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround71.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround71
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM iec958
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
Apr 22 19 09:51:58 PM alarmd[3318]: [main.INFO] Python 3.5.3 (default, Sep 27 2018, 17:25:39) 
[GCC 6.3.0 20170516]
Apr 22 19 09:51:58 PM alarmd[3318]: [main.INFO] Starting in no-fork mode
Apr 22 19 09:51:58 PM alarmd[3318]: [status.INFO] Loading config from /var/lib/alarmd/alarmd.db
Apr 22 19 09:51:58 PM alarmd[3318]: [main.INFO] Ready, listening for alarms
Apr 22 19 09:51:58 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:51:59 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:51:59 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:51:59 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:52:00 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:52:00 PM alarmd[3318]: [callup.DEBUG] Number 043
Apr 22 19 09:52:00 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:52:00 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:52:30 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:52:30 PM alarmd[3318]: [callup.INFO] Phone On The Hook
Apr 22 19 09:52:30 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:52:30 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:52:30 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:52:30 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:52:36 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:52:38 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:52:38 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:52:39 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:52:39 PM alarmd[3318]: [callup.DEBUG] Number 043
Apr 22 19 09:52:39 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:52:39 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:53:09 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:53:09 PM alarmd[3318]: [callup.INFO] Phone On The Hook
Apr 22 19 09:53:09 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:53:09 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:53:09 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:53:09 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:53:15 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:53:17 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:53:17 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:53:18 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:53:18 PM alarmd[3318]: [callup.DEBUG] Number 043
Apr 22 19 09:53:18 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:53:18 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:53:48 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:53:48 PM alarmd[3318]: [callup.INFO] Phone On The Hook
Apr 22 19 09:53:48 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:53:48 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:53:48 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:53:48 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:53:54 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:53:56 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:53:56 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:53:57 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:53:57 PM alarmd[3318]: [callup.DEBUG] Number 043
Apr 22 19 09:53:57 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:53:57 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:54:28 PM alarmd[3318]: [callup.DEBUG] Number 433
Apr 22 19 09:54:28 PM alarmd[3318]: [callup.INFO] Phone On The Hook
Apr 22 19 09:54:28 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:54:28 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:54:28 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:54:28 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:54:33 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:54:35 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:54:35 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:54:35 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:54:35 PM alarmd[3318]: [callup.DEBUG] Number 044
Apr 22 19 09:54:36 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:54:36 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:54:36 PM alarmd[3318]: [callup.INFO] Alarm Call In Received
Apr 22 19 09:54:36 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:54:36 PM alarmd[3318]: [callup.INFO] Collecting Alarm Codes
Apr 22 19 09:54:36 PM alarmd[3318]: [handshake.INFO] Handshake Initiated
Apr 22 19 09:55:06 PM alarmd[3318]: [callup.INFO] Alarm Hung Up
Apr 22 19 09:55:06 PM alarmd[3318]: [handshake.INFO] Handshake Complete
Apr 22 19 09:55:06 PM alarmd[3318]: [callup.INFO] Code String: 
Apr 22 19 09:55:06 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:55:06 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:55:06 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:55:06 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:55:12 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:55:14 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:55:14 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:55:14 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:55:14 PM alarmd[3318]: [callup.DEBUG] Number 044
Apr 22 19 09:55:15 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:55:15 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:55:15 PM alarmd[3318]: [callup.INFO] Alarm Call In Received
Apr 22 19 09:55:15 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:55:15 PM alarmd[3318]: [callup.INFO] Collecting Alarm Codes
Apr 22 19 09:55:15 PM alarmd[3318]: [handshake.INFO] Handshake Initiated
Apr 22 19 09:55:45 PM alarmd[3318]: [callup.INFO] Alarm Hung Up
Apr 22 19 09:55:45 PM alarmd[3318]: [handshake.INFO] Handshake Complete
Apr 22 19 09:55:45 PM alarmd[3318]: [callup.INFO] Code String: 
Apr 22 19 09:55:45 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:55:45 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:55:45 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:55:45 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:55:51 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:55:53 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:55:53 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:55:53 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:55:53 PM alarmd[3318]: [callup.DEBUG] Number 044
Apr 22 19 09:55:54 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:55:54 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:55:54 PM alarmd[3318]: [callup.INFO] Alarm Call In Received
Apr 22 19 09:55:54 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:55:54 PM alarmd[3318]: [callup.INFO] Collecting Alarm Codes
Apr 22 19 09:55:54 PM alarmd[3318]: [handshake.INFO] Handshake Initiated
Apr 22 19 09:56:24 PM alarmd[3318]: [callup.INFO] Alarm Hung Up
Apr 22 19 09:56:24 PM alarmd[3318]: [handshake.INFO] Handshake Complete
Apr 22 19 09:56:24 PM alarmd[3318]: [callup.INFO] Code String: 
Apr 22 19 09:56:24 PM alarmd[3318]: [status.INFO] No new events found!
Apr 22 19 09:56:24 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:56:24 PM alarmd[3318]: [notify.INFO] No events for notification
Apr 22 19 09:56:24 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:56:30 PM alarmd[3318]: [callup.INFO] Phone Off The Hook
Apr 22 19 09:56:32 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:56:32 PM alarmd[3318]: [callup.DEBUG] Number 004
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.DEBUG] Digit 4
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.DEBUG] Number 044
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.DEBUG] Digit 3
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.INFO] Alarm Call In Received
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.DEBUG] Number 443
Apr 22 19 09:56:33 PM alarmd[3318]: [callup.INFO] Collecting Alarm Codes
Apr 22 19 09:56:33 PM alarmd[3318]: [handshake.INFO] Handshake Initiated
Apr 22 19 09:56:50 PM alarmd[3318]: [callup.INFO] Alarm Hung Up
Apr 22 19 09:56:50 PM alarmd[3318]: [handshake.INFO] Handshake Complete
Apr 22 19 09:56:50 PM alarmd[3318]: [callup.INFO] Code String: 0000181628000004000018162800000400001816270000050000181627000005
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] New Events
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] MA: Installer Lead Out 
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] MA: Installer Lead Out 
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] MA: Installer Lead In 
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] MA: Installer Lead In 
Apr 22 19 09:56:50 PM alarmd[3318]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 09:56:51 PM alarmd[3318]: [main.DEBUG] Timeout: None
Apr 22 19 09:56:51 PM alarmd[3359]: [notify.INFO] Sending notifications...

However more often than not they are not, and the alarm hangs up early:

(venv3) pi@raspberrypi:~ $ sudo /home/pi/venv3/bin/alarmd --no-fork --debug
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.front.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM front
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround40.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround40
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround41
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround50
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround51
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.surround71.0:CARD=0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM surround71
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM iec958
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_alsa.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
Apr 22 19 10:30:09 PM alarmd[4307]: [main.INFO] Python 3.5.3 (default, Sep 27 2018, 17:25:39) 
[GCC 6.3.0 20170516]
Apr 22 19 10:30:10 PM alarmd[4307]: [main.INFO] Starting in no-fork mode
Apr 22 19 10:30:10 PM alarmd[4307]: [status.INFO] Loading config from /var/lib/alarmd/alarmd.db
Apr 22 19 10:30:10 PM alarmd[4307]: [main.INFO] Ready, listening for alarms
Apr 22 19 10:30:10 PM alarmd[4307]: [main.DEBUG] Timeout: None
Apr 22 19 10:30:26 PM alarmd[4307]: [callup.INFO] Phone Off The Hook
Apr 22 19 10:30:32 PM alarmd[4307]: [callup.DEBUG] Number 000
Apr 22 19 10:30:32 PM alarmd[4307]: [callup.INFO] Phone On The Hook
Apr 22 19 10:30:32 PM alarmd[4307]: [status.INFO] No new events found!
Apr 22 19 10:30:32 PM alarmd[4307]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 10:30:32 PM alarmd[4307]: [notify.INFO] No events for notification
Apr 22 19 10:30:32 PM alarmd[4307]: [main.DEBUG] Timeout: None
Apr 22 19 10:30:36 PM alarmd[4307]: [callup.INFO] Phone Off The Hook
Apr 22 19 10:30:42 PM alarmd[4307]: [callup.DEBUG] Number 000
Apr 22 19 10:30:42 PM alarmd[4307]: [callup.INFO] Phone On The Hook
Apr 22 19 10:30:42 PM alarmd[4307]: [status.INFO] No new events found!
Apr 22 19 10:30:42 PM alarmd[4307]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 10:30:42 PM alarmd[4307]: [notify.INFO] No events for notification
Apr 22 19 10:30:42 PM alarmd[4307]: [main.DEBUG] Timeout: None
Apr 22 19 10:30:47 PM alarmd[4307]: [callup.INFO] Phone Off The Hook
Apr 22 19 10:30:53 PM alarmd[4307]: [callup.DEBUG] Number 000
Apr 22 19 10:30:53 PM alarmd[4307]: [callup.INFO] Phone On The Hook
Apr 22 19 10:30:53 PM alarmd[4307]: [status.INFO] No new events found!
Apr 22 19 10:30:53 PM alarmd[4307]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 10:30:53 PM alarmd[4307]: [notify.INFO] No events for notification
Apr 22 19 10:30:53 PM alarmd[4307]: [main.DEBUG] Timeout: None
Apr 22 19 10:30:58 PM alarmd[4307]: [callup.INFO] Phone Off The Hook
Apr 22 19 10:31:04 PM alarmd[4307]: [callup.DEBUG] Number 000
Apr 22 19 10:31:04 PM alarmd[4307]: [callup.INFO] Phone On The Hook
Apr 22 19 10:31:04 PM alarmd[4307]: [status.INFO] No new events found!
Apr 22 19 10:31:04 PM alarmd[4307]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 10:31:04 PM alarmd[4307]: [notify.INFO] No events for notification
Apr 22 19 10:31:04 PM alarmd[4307]: [main.DEBUG] Timeout: None
Apr 22 19 10:31:14 PM alarmd[4307]: [callup.INFO] Phone Off The Hook
Apr 22 19 10:31:15 PM alarmd[4307]: [callup.DEBUG] Number 000
Apr 22 19 10:31:15 PM alarmd[4307]: [callup.INFO] Phone On The Hook
Apr 22 19 10:31:15 PM alarmd[4307]: [status.INFO] No new events found!
Apr 22 19 10:31:15 PM alarmd[4307]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 22 19 10:31:15 PM alarmd[4307]: [notify.INFO] No events for notification
Apr 22 19 10:31:15 PM alarmd[4307]: [main.DEBUG] Timeout: None

It is worth calling out this feels like an initialisation issue - when it work it works consistently until the application is restarted. (then it may, or may not work for the following instance)

Is this something you've seen before? I've tried running the MagicJack through a number of different usb hubs, a different RPi etc etc and the only consistent thing is how inconsistent it is! The only guess I have is that due to being located in the UK my equipment expects 50v, and US standard is 48v, but thats a bit of a stretch. Are you aware of any specifics it might be worth tweaking?

Thanks again

Alex

scudre commented 5 years ago

Hey, @alexp789 first of all thanks for checking out the project!

I had a few questions/observations:

In the first output, I noticed that the alarm calls '443' multiple times, and then hangs up. Only after the 8th or so try do the Installer Lead In/Lead out codes get recorded. What you should see is the alarm call once, and be able to transmit the codes on the first attempt. Two questions:

  1. Was that the alarm attempting all of those times before it successfully went through?
  2. What is the phone number that your alarm system is programmed to call? Is it 443?

For the second output, its just showing '000'. Which looks like the MagicJack isn't detecting the DTMF codes at all, just the on/off of the phone.

  1. I've seen this happen randomly if the MagicJack isn't connected to a powered USB hub. You mention a USB hub, but is it powered?
  2. After the application fails to work on restarting of it. What does it take to get it to work again? Keep restarting the daemon, or do you need to restart the whole system?
  3. What distro are you using?
alexp789 commented 5 years ago

Thank you for the prompt reply, apologies for my delay, I was away for the weekend. To answer the questions:

  1. Was that the alarm attempting all of those times before it successfully went through? - Apologies I believe that is me confusing the situation. I had to tweak the volumes in alsamixer to get it to work properly, I believe this is an example where I did this and it started working.
  2. What is the phone number that your alarm system is programmed to call? Is it 443? - Correct it is set to dial 443.
  3. You mention a USB hub, but is it powered? - I've tried a number of different powered USB hubs, they don't seem to influence the success rate either way.
  4. What does it take to get it to work again? - I'm currently testing and will capture some better outputs of success and will also document exactly what, if any, changes led to it working.
  5. What distro are you using? - Raspbian, latest build, python 3.5 running from a venv.

I'm not sure if this would help, but the noises coming from the line relay in the alarm don't seem to line up with the output from the application:

Apr 30 19 09:38:22 PM alarmd[727]: [main.INFO] Python 3.5.3 (default, Sep 27 2018, 17:25:39) 
[GCC 6.3.0 20170516]
Apr 30 19 09:38:22 PM alarmd[727]: [main.INFO] Starting in no-fork mode
Apr 30 19 09:38:22 PM alarmd[727]: [status.INFO] Loading config from /var/lib/alarmd/alarmd.db
Apr 30 19 09:38:22 PM alarmd[727]: [main.INFO] Ready, listening for alarms
Apr 30 19 09:38:22 PM alarmd[727]: [main.DEBUG] Timeout: None
<click from alarm taking phone off the hook>
Apr 30 19 09:38:26 PM alarmd[727]: [callup.INFO] Phone Off The Hook
Apr 30 19 09:38:33 PM alarmd[727]: [callup.DEBUG] Number 000
Apr 30 19 09:38:33 PM alarmd[727]: [callup.INFO] Phone On The Hook
Apr 30 19 09:38:33 PM alarmd[727]: [status.INFO] No new events found!
Apr 30 19 09:38:33 PM alarmd[727]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 30 19 09:38:33 PM alarmd[727]: [notify.INFO] No events for notification
Apr 30 19 09:38:33 PM alarmd[727]: [main.DEBUG] Timeout: None
<click from alarm putting phone back on hook>
Apr 30 19 09:38:37 PM alarmd[727]: [callup.INFO] Phone Off The Hook
Apr 30 19 09:38:43 PM alarmd[727]: [callup.DEBUG] Number 000
Apr 30 19 09:38:43 PM alarmd[727]: [callup.INFO] Phone On The Hook
Apr 30 19 09:38:43 PM alarmd[727]: [status.INFO] No new events found!
Apr 30 19 09:38:43 PM alarmd[727]: [status.INFO] Saving config to /var/lib/alarmd/alarmd.db
Apr 30 19 09:38:43 PM alarmd[727]: [notify.INFO] No events for notification
Apr 30 19 09:38:43 PM alarmd[727]: [main.DEBUG] Timeout: None

Note how the application has decided the phone is on the hook before I can hear the relay physically closing?

alexp789 commented 5 years ago

Having done some additional investigation, could I trouble someone to test the line voltage output from their MagicJack? Mine is outputting 40V (50V is the standard in the UK) - which I'm surmising could be the cause of my issues. Does anyone know of a way to instruct the MagicJack to increase its output, or could mine just be faulty?

Thanks again

Alex

scudre commented 5 years ago

I can try measuring the voltage on mine this evening (I'm on the US west coast.)

On Mon, May 27, 2019, 1:06 PM Alex Pearson notifications@github.com wrote:

Having done some additional investigation, could I trouble someone to test the line voltage output from their MagicJack? Mine is outputting 40V (50V is the standard in the UK) - which I'm surmising could be the cause of my issues. Does anyone know of a way to instruct the MagicJack to increase its output, or could mine just be faulty?

Thanks again

Alex

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/scudre/alarm-central-station-receiver/issues/52?email_source=notifications&email_token=AE2IOP3AILF3AJMDUPAI2DDPXQ5OFA5CNFSM4HHS5JL2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODWKOGNA#issuecomment-496296756, or mute the thread https://github.com/notifications/unsubscribe-auth/AE2IOP36JWHJHDURYT3V3QDPXQ5OFANCNFSM4HHS5JLQ .

scudre commented 5 years ago

@alexp789 I checked the voltage, and I'm also geting 40V:

Some other thoughts:

One possibility is that the alarm system is waiting to hear a dialtone from the MagicJack. I noticed that the MagicJack seems to randomly output a dialtone. Shot in the dark, but maybe its working when the MagicJack outputs the dialtone. And then when it's not that's when you see the alarm picking up and then hanging up. It listens for a dialtone, doesn't hear one so it hangs up to try again.

For my alarm system it had a setting to not listen for the dialtone. I looked online for a manual for your system, though not sure if this is the same one or not: http://www.pazhelectronic.com/LinkClick.aspx?fileticket=An3u7vyGJmM%3D&tabid=78 Unfortunately I couldn't find any setting in there about turning off listening for the dialtone. But its worth looking for that in your manual.

One idea to confirm this is to hook up a phone to your MagicJack when you know the alarm can successfully call, and see if you hear a dialtone. Then when its not working try again and see if a dial tone is missing. Though doesn't UK use a different dialtone frequeny than North America? Hmm.

Anyway, if we can narrow it down to that actually being the case, I can go about trying to get the dialtone working consistently.

alexp789 commented 5 years ago

Right, some progress @scudre! So after some very long-winded testing I've found the below hacky fix unexpectedly makes it 100% reliable. (Both the alarm always think there is a line there, and the application always receives the DMTF correctly). I have this in-use at the moment and working fine: troubleshooting Would you be open to a PR for something like this? I'm not sure you'd want to always make it play the handshake as I do above, but maybe others would find this feature useful? Maybe adding it as an argument link this: argument option *I've not tested this branch yet.

Thanks

Alex

scudre commented 5 years ago

@alexp789 to recap, if you have the handshake run at start up that will ensure everything works okay? I wonder if having any sound wav play would accomplish this. If so we could modify the init in handshake.py to play a sound at start.