activate_scenario.sh
Thu Dec 19 20:38:49 CET 2024
scenario: vorraumOn
phoneName: 1

scenario: 'Vorzimmer EIN' - 'vorraumOn' - 'vorraumon'

VZ Licht (/srv/www/viehai/shelly/log_scenarios/2024/12/19/_0.log)

vorher: 20:38:49.794

  "ison": true,
  "has_timer": false,
  "timer_started": 0,
  "timer_duration": 0,
  "timer_remaining": 0,
  "overpower": false,
  "source": "input"

nachher: 20:38:49.907
Dauer: 114 msec phName: 'phoneName:'1''

scenario: 'Vorzimmer EIN' - 'vorraumOn' - 'vorraumon'

urls : 1
vorher : 20:38:49.775
nachher: 20:38:49.913
Dauer : 138 msec
outfile: '/srv/www/viehai/shelly/log_scenarios/2024/12/19//scene_vorraumOn_20241219_203849.txt'

syslog

Dec 19 20:35:00 srv4hai named[30406]: resolver priming query complete
Dec 19 20:35:01 srv4hai CRON[31144]: (root) CMD (/etc/linetest/linetest.sh)
Dec 19 20:35:03 srv4hai named[30406]: resolver priming query complete
Dec 19 20:35:04 srv4hai fetchmail[1651]: 7 messages (7 seen) for rozmig at mail.akis.at (1753652 octets).
Dec 19 20:35:12 srv4hai fetchmail[1651]: 59714 messages (59714 seen) for tmiglinci at mail.akis.at (614321117 octets).
Dec 19 20:35:17 srv4hai fetchmail[1651]: 11253 messages (11253 seen) for srozum at mail.akis.at (1348138645 octets).
Dec 19 20:35:23 srv4hai fetchmail[1651]: 27954 messages (27954 seen) for mrozum at mail.akis.at (513370970 octets).
Dec 19 20:35:24 srv4hai fetchmail[1651]: 1161 messages (1161 seen) for admin@bastelstube.wien at pop3.world4you.com (52202045 octets).
Dec 19 20:35:26 srv4hai named[30406]: resolver priming query complete
Dec 19 20:35:39 srv4hai dovecot: imap-login: Login: user=, method=PLAIN, rip=::1, lip=::1, mpid=31154, secured, session=
Dec 19 20:35:39 srv4hai dovecot: imap(miglincit)<31154>: Logged out in=137 out=1088 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Dec 19 20:35:43 srv4hai mosquitto[29419]: New connection from 192.168.12.101 on port 1883.
Dec 19 20:35:43 srv4hai mosquitto[29419]: Socket error on client , disconnecting.
Dec 19 20:35:55 srv4hai named[30406]: resolver priming query complete
Dec 19 20:36:01 srv4hai CRON[31159]: (root) CMD (/etc/linetest/linetest.sh)
Dec 19 20:36:03 srv4hai named[30406]: resolver priming query complete
Dec 19 20:36:39 srv4hai mosquitto[29419]: New connection from 192.168.12.101 on port 1883.
Dec 19 20:36:39 srv4hai mosquitto[29419]: Socket error on client , disconnecting.
Dec 19 20:37:01 srv4hai CRON[31169]: (root) CMD (/etc/linetest/linetest.sh)
Dec 19 20:37:02 srv4hai postfix/anvil[31124]: statistics: max connection rate 1/60s for (smtp:154.203.197.200) at Dec 19 20:33:18
Dec 19 20:37:02 srv4hai postfix/anvil[31124]: statistics: max connection count 1 for (smtp:154.203.197.200) at Dec 19 20:33:18
Dec 19 20:37:02 srv4hai postfix/anvil[31124]: statistics: max cache size 2 at Dec 19 20:33:38
Dec 19 20:37:02 srv4hai named[30406]: resolver priming query complete
Dec 19 20:37:11 srv4hai named[30406]: resolver priming query complete
Dec 19 20:37:31 srv4hai named[30406]: resolver priming query complete
Dec 19 20:37:31 srv4hai postfix/smtpd[31183]: connect from unknown[80.94.95.239]
Dec 19 20:37:31 srv4hai postfix/smtpd[31183]: warning: unknown[80.94.95.239]: SASL LOGIN authentication failed: Invalid authentication mechanism
Dec 19 20:37:31 srv4hai postfix/smtpd[31183]: disconnect from unknown[80.94.95.239] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
Dec 19 20:37:36 srv4hai mosquitto[29419]: New connection from 192.168.12.101 on port 1883.
Dec 19 20:37:36 srv4hai mosquitto[29419]: Socket error on client , disconnecting.
Dec 19 20:38:01 srv4hai CRON[31194]: (root) CMD (/etc/linetest/linetest.sh)
Dec 19 20:38:17 srv4hai dhcpd[4995]: DHCPDISCOVER from e8:78:29:c0:c2:4e via enp2s0
Dec 19 20:38:17 srv4hai dhcpd[4995]: DHCPOFFER on 192.168.12.61 to e8:78:29:c0:c2:4e via enp2s0
Dec 19 20:38:17 srv4hai dhcpd[4995]: execute_statement argv[0] = /srv/www/viehai/shelly/smartphone.sh
Dec 19 20:38:17 srv4hai dhcpd[4995]: execute_statement argv[1] = 192.168.12.61
Dec 19 20:38:17 srv4hai dhcpd[4995]: execute_statement argv[2] = fpThomas
Dec 19 20:38:17 srv4hai common[31202]: SHELLY common.sh inkludiert von /srv/www/viehai/shelly/smartphone.sh
Dec 19 20:38:17 srv4hai smartphone.sh: SHELLY - ping_SP.sh started for phoneIP: '192.168.12.61' / 'fpThomas' / '0'
Dec 19 20:38:17 srv4hai common[31217]: SHELLY common.sh inkludiert von /srv/www/viehai/shelly//ping_SP.sh
Dec 19 20:38:17 srv4hai dhcpd[4995]: DHCPREQUEST for 192.168.12.61 (192.168.12.252) from e8:78:29:c0:c2:4e via enp2s0
Dec 19 20:38:17 srv4hai dhcpd[4995]: DHCPACK on 192.168.12.61 to e8:78:29:c0:c2:4e via enp2s0
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f9330095370 192.168.12.252#46899/key rndc-key: updating zone 'viehai.at/IN': update unsuccessful: fpThomas.viehai.at: 'name not in use' prerequisite not satisfied (YXDOMAIN)
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f93380a5c40 192.168.12.252#56143/key rndc-key: signer "rndc-key" approved
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f93380a5c40 192.168.12.252#56143/key rndc-key: updating zone 'viehai.at/IN': deleting rrset at 'fpThomas.viehai.at' TXT
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f93380a5c40 192.168.12.252#56143/key rndc-key: updating zone 'viehai.at/IN': adding an RR at 'fpThomas.viehai.at' TXT "310ebd0eafccd9c2e311facf8a4b0e4ad2"
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f93380a5c40 192.168.12.252#56143/key rndc-key: updating zone 'viehai.at/IN': deleting rrset at 'fpThomas.viehai.at' A
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f93380a5c40 192.168.12.252#56143/key rndc-key: updating zone 'viehai.at/IN': adding an RR at 'fpThomas.viehai.at' A 192.168.12.61
Dec 19 20:38:17 srv4hai dhcpd[4995]: Added new forward map from fpThomas.viehai.at to 192.168.12.61
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f931006ae50 192.168.12.252#51691/key rndc-key: signer "rndc-key" approved
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f931006ae50 192.168.12.252#51691/key rndc-key: updating zone '12.168.192.in-addr.arpa/IN': deleting rrset at '61.12.168.192.in-addr.arpa' PTR
Dec 19 20:38:17 srv4hai named[30406]: client @0x7f931006ae50 192.168.12.252#51691/key rndc-key: updating zone '12.168.192.in-addr.arpa/IN': adding an RR at '61.12.168.192.in-addr.arpa' PTR fpThomas.viehai.at.
Dec 19 20:38:17 srv4hai dhcpd[4995]: Added reverse map from 61.12.168.192.in-addr.arpa. to fpThomas.viehai.at
Dec 19 20:38:17 srv4hai ping_SP[31217]: SHELLY ping_SP.sh started from smartphone, user:'root'
Dec 19 20:38:17 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:18 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:19 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:21 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:22 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:27 srv4hai common[31248]: SHELLY common.sh inkludiert von /srv/www/viehai/shelly//check_presence.sh
Dec 19 20:38:27 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:28 srv4hai common.sh: SHELLY: BTstatus[0]:'BTdweet_older_60sec' dweetAge:'84'=1734637108-1734637024
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (0) found /srv/www/viehai/shelly//meter/ping_SP_0.LIVE and BTdweet_older_60sec//srv/www/viehai/shelly//meter/BTscan_BTid_0.No
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (ping_SP__smartphone)-(0) found '/srv/www/viehai/shelly//meter/ping_SP_0.LIVE' for what: 'coming'
Dec 19 20:38:28 srv4hai common.sh: SHELLY: BTstatus[1]:'BTdweet_older_60sec' dweetAge:'84'=1734637108-1734637024
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (1) found /srv/www/viehai/shelly//meter/ping_SP_1.DEAD and BTdweet_older_60sec//srv/www/viehai/shelly//meter/BTscan_BTid_1.Yes
Dec 19 20:38:28 srv4hai common.sh: SHELLY: BTstatus[2]:'BTdweet_older_60sec' dweetAge:'84'=1734637108-1734637024
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (2) found /srv/www/viehai/shelly//meter/ping_SP_2.DEAD and BTdweet_older_60sec//srv/www/viehai/shelly//meter/BTscan_BTid_2.No
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (ping_SP__smartphone)-(0) what: 'coming' - persPresent: '(__/LIVE) (__/__) (__/__)' - anyPresent: 'true' - otherPresent:'false'
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY - check 'coming': anyPresent(true) - lScene(scene_offAll) - sceneONsmall(vorraumOn)
Dec 19 20:38:28 srv4hai check_presence[31248]: SHELLY (ping_SP__smartphone)-(0)-coming: activate_scenario.shtml: vorraumOn
Dec 19 20:38:28 srv4hai activate_scenario[31386]: SHELLY scenario: 'vorraumOn(vorraumon)' started
Dec 19 20:38:28 srv4hai activate_scenario[31386]: SHELLY dayState='night' <--> DayTime=checked NightTime=checked - phoneName:'0'
Dec 19 20:38:28 srv4hai activate_scenario[31386]: SHELLY scenario: 'vorraumOn(vorraumon)' TO BE EXECUTED, phoneName:'0'
Dec 19 20:38:28 srv4hai postfix/pickup[24984]: 4BAAE63463: uid=33 from=
Dec 19 20:38:28 srv4hai postfix/cleanup[31436]: 4BAAE63463: message-id=<20241219193828.4BAAE63463@mail.viehai.at>
Dec 19 20:38:28 srv4hai postfix/qmgr[8566]: 4BAAE63463: from=, size=8975, nrcpt=1 (queue active)
Dec 19 20:38:28 srv4hai activate_scenario[31386]: SHELLY: scenario: 'vorraumOn(vorraumon)'-'shelly-03'-'VZ Licht' --> '0?turn=on'
Dec 19 20:38:28 srv4hai proc_url[31453]: SHELLY: OF:'/srv/www/viehai/shelly/log_scenarios/2024/12/19/_0.log' - shellyUsage:'VZ Licht' - scUrl:'http://192.168.12.103/relay/0?turn=on' - phName:'phoneName:'0''
Dec 19 20:38:28 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:28 srv4hai activate_scenario[31386]: SHELLY scenario: 'vorraumOn(vorraumon)' took 110 msec, phoneName:'0'
Dec 19 20:38:28 srv4hai ping_SP[31217]: SHELLY check_presence.sh coming 0 ping_SP__smartphone
Dec 19 20:38:29 srv4hai postfix/relay/smtp[31449]: 4BAAE63463: to=, relay=mx02.nic.name[209.131.158.56]:25, delay=0.97, delays=0.02/0.01/0.69/0.26, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 1725280091)
Dec 19 20:38:29 srv4hai postfix/qmgr[8566]: 4BAAE63463: removed
Dec 19 20:38:30 srv4hai ping_SP[31217]: SHELLY - new process for '192.168.12.61' - '/srv/www/viehai/shelly//meter/ping_SP_0' @~1734637110
Dec 19 20:38:34 srv4hai mosquitto[29419]: New connection from 192.168.12.101 on port 1883.
Dec 19 20:38:34 srv4hai mosquitto[29419]: Socket error on client , disconnecting.
Dec 19 20:38:35 srv4hai dhcpd[4995]: DHCPDISCOVER from 08:3a:8d:d0:46:5a via enp2s0
Dec 19 20:38:35 srv4hai dhcpd[4995]: DHCPOFFER on 192.168.12.5 to 08:3a:8d:d0:46:5a via enp2s0
Dec 19 20:38:35 srv4hai dhcpd[4995]: execute_statement argv[0] = /srv/www/viehai/shelly/dhcpcommit.sh
Dec 19 20:38:35 srv4hai dhcpd[4995]: execute_statement argv[1] = 192.168.12.5
Dec 19 20:38:35 srv4hai dhcpd[4995]: execute_statement argv[2] = btscan1
Dec 19 20:38:35 srv4hai dhcpd[4995]: DHCPREQUEST for 192.168.12.5 (192.168.12.252) from 08:3a:8d:d0:46:5a via enp2s0
Dec 19 20:38:35 srv4hai dhcpd[4995]: DHCPACK on 192.168.12.5 to 08:3a:8d:d0:46:5a via enp2s0
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f931001f430 192.168.12.252#55907/key rndc-key: updating zone 'viehai.at/IN': update unsuccessful: btscan1.viehai.at: 'name not in use' prerequisite not satisfied (YXDOMAIN)
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f9348054f20 192.168.12.252#48553/key rndc-key: signer "rndc-key" approved
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f9348054f20 192.168.12.252#48553/key rndc-key: updating zone 'viehai.at/IN': deleting rrset at 'btscan1.viehai.at' TXT
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f9348054f20 192.168.12.252#48553/key rndc-key: updating zone 'viehai.at/IN': adding an RR at 'btscan1.viehai.at' TXT "000118916176265854cff71f762ffe0635"
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f9348054f20 192.168.12.252#48553/key rndc-key: updating zone 'viehai.at/IN': deleting rrset at 'btscan1.viehai.at' A
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f9348054f20 192.168.12.252#48553/key rndc-key: updating zone 'viehai.at/IN': adding an RR at 'btscan1.viehai.at' A 192.168.12.5
Dec 19 20:38:35 srv4hai dhcpcommit.sh: SHELLY ip:'192.168.12.5'(5) device 'btscan1'
Dec 19 20:38:35 srv4hai dhcpd[4995]: Added new forward map from btscan1.viehai.at to 192.168.12.5
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f931c02c6e0 192.168.12.252#57551/key rndc-key: signer "rndc-key" approved
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f931c02c6e0 192.168.12.252#57551/key rndc-key: updating zone '12.168.192.in-addr.arpa/IN': deleting rrset at '5.12.168.192.in-addr.arpa' PTR
Dec 19 20:38:35 srv4hai named[30406]: client @0x7f931c02c6e0 192.168.12.252#57551/key rndc-key: updating zone '12.168.192.in-addr.arpa/IN': adding an RR at '5.12.168.192.in-addr.arpa' PTR btscan1.viehai.at.
Dec 19 20:38:35 srv4hai dhcpd[4995]: Added reverse map from 5.12.168.192.in-addr.arpa. to btscan1.viehai.at
Dec 19 20:38:35 srv4hai dhcpcommit.sh: SHELLY device 'btscan1' known and accepted
Dec 19 20:38:38 srv4hai common[31502]: SHELLY common.sh inkludiert von ./bt_scan.sh
Dec 19 20:38:38 srv4hai common[31511]: SHELLY common.sh inkludiert von ./bt_scan.sh
Dec 19 20:38:39 srv4hai dovecot: imap-login: Login: user=, method=PLAIN, rip=::1, lip=::1, mpid=31534, secured, session=<6+JWraQpltcAAAAAAAAAAAAAAAAAAAAB>
Dec 19 20:38:39 srv4hai dovecot: imap(miglincit)<31534><6+JWraQpltcAAAAAAAAAAAAAAAAAAAAB>: Logged out in=137 out=1088 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Dec 19 20:38:41 srv4hai named[30406]: resolver priming query complete
Dec 19 20:38:43 srv4hai ping_SP[31217]: SHELLY (0) - ping 192.168.12.61 0 sucessfully  @~1734637123 - 'ping_SP_0'
Dec 19 20:38:43 srv4hai ping_SP[31217]: SHELLY (0) - ping 192.168.12.61 pCnt:'1'
Dec 19 20:38:48 srv4hai bt_scan[31502]: SHELLY - who: 'Thomas' / phoneName: 'FP4_Thomas' / '0' / shellyIP: '192.168.12.61' - found: 'Yes'
Dec 19 20:38:48 srv4hai bt_scan[31511]: SHELLY - who: 'Grete' / phoneName: 'S20_Grete' / '1' / shellyIP: '192.168.12.62' - found: 'Yes'
Dec 19 20:38:48 srv4hai bt_scan[31502]: SHELLY - ping_SP.sh already running for BTmac: '0' - IPv4: '192.168.12.61'
Dec 19 20:38:48 srv4hai bt_scan[31511]: SHELLY - ping_SP.sh started for BTmac: '1' - IPv4: '192.168.12.62'
Dec 19 20:38:48 srv4hai common[31587]: SHELLY common.sh inkludiert von /srv/www/viehai/shelly//ping_SP.sh
Dec 19 20:38:48 srv4hai ping_SP[31587]: SHELLY ping_SP.sh started from bt_scan, user:'www-data'
Dec 19 20:38:48 srv4hai common[31609]: SHELLY common.sh inkludiert von /srv/www/viehai/shelly//check_presence.sh
Dec 19 20:38:49 srv4hai common.sh: SHELLY: BTstatus[0]:'BTdweet_not_set' dweetAge:'1'=1734637129-1734637128
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (0) found /srv/www/viehai/shelly//meter/ping_SP_0.LIVE and BTdweet_not_set//srv/www/viehai/shelly//meter/BTscan_BTid_0.Yes
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (ping_SP__bt_scan)-(1) found '/srv/www/viehai/shelly//meter/ping_SP_0.LIVE' for what: 'coming'
Dec 19 20:38:49 srv4hai common.sh: SHELLY: BTstatus[1]:'BTdweet_not_set' dweetAge:'1'=1734637129-1734637128
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (1) found /srv/www/viehai/shelly//meter/ping_SP_1.TRY} and BTdweet_not_set//srv/www/viehai/shelly//meter/BTscan_BTid_1.Yes
Dec 19 20:38:49 srv4hai common.sh: SHELLY: BTstatus[2]:'BTdweet_not_set' dweetAge:'1'=1734637129-1734637128
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (2) found /srv/www/viehai/shelly//meter/ping_SP_2.DEAD and BTdweet_not_set//srv/www/viehai/shelly//meter/BTscan_BTid_2.No
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (ping_SP__bt_scan)-(1) what: 'coming' - persPresent: '(__/LIVE) (__/__) (__/__)' - anyPresent: 'true' - otherPresent:'true'
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY - check 'coming': anyPresent(true) - lScene(scene_vorraumOn) - sceneONsmall(vorraumOn)
Dec 19 20:38:49 srv4hai check_presence[31609]: SHELLY (ping_SP__bt_scan)-(1)-coming: activate_scenario.shtml: vorraumOn
Dec 19 20:38:49 srv4hai activate_scenario[31738]: SHELLY scenario: 'vorraumOn(vorraumon)' started
Dec 19 20:38:49 srv4hai activate_scenario[31738]: SHELLY dayState='night' <--> DayTime=checked NightTime=checked - phoneName:'1'

finished