Autor Thema: Firmware zu CUL, CUNX und Co. mit Timestamp Option ASKSIN tsculfw V0.39  (Gelesen 264586 mal)

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #240 am: 09 Oktober 2016, 15:38:03 »
Hallo Christian,

kannst Du beides bitte nochmal mit verbose 4 beim NanoCUL loggen.
Im Rolladen-Log alleine ist nicht zu sehen, was wann gesendet und empfangen wird.
Die Einstellungen beim NanoCUL sehen erst mal gut aus.

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #241 am: 09 Oktober 2016, 23:21:18 »
Hallo Ansgar!

Habe jetzt nochmal mit verbose=4 die Logs gezogen, sieht aber leider nicht besser aus:

2016-10-09_23:15:03 WoZi_ErkerLi_Rollo set_on
2016-10-09_23:15:03 WoZi_ErkerMi_Rollo set_on
2016-10-09_23:15:14 WoZi_ErkerMi_Rollo aesKeyNbr: 00
2016-10-09_23:15:14 WoZi_ErkerMi_Rollo RAWMSG: A111DA0024AD222D3AA7804FEDD1CACD21900::-76.5:nanoCULHomeMatic
2016-10-09_23:15:14 WoZi_ErkerMi_Rollo RSSI: -76.5
2016-10-09_23:15:15 WoZi_ErkerLi_Rollo aesKeyNbr: 02
2016-10-09_23:15:15 WoZi_ErkerLi_Rollo RSSI: -55.5
2016-10-09_23:15:15 WoZi_ErkerLi_Rollo RAWMSG: A1115A0024AD27AD3AA7804956622D3DDA102::-55.5:nanoCULHomeMatic

Viele Grüße,
Christian

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #242 am: 09 Oktober 2016, 23:46:13 »
Hallo Christian,

beim NanoCUL musst Du das Attribut verbose auf 4 setzen.
Nur dann werden die Sende- und Empfangsdaten des NanoCUL geloggt.

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #243 am: 11 Oktober 2016, 08:15:09 »
Hallo Ansgar!

Habe gestern noch ein paar Versuche gefahren. Auch mit verbose=4 auf dem nanoCUL bekomme ich weder vom CUL noch von der VCCU irgendeinen Log-Eintrag geschrieben. Die Logs der Aktoren sehen immer recht ähnlich aus, wobei ich 2x die Situation hatte, dass nun zwei bzw. einer von dreien auch bei sign=on losgefahren ist. Leider ist das aber nicht dauerhaft so, beim nächsten mal bleiben sie wieder alle 3 stehen.

Hier nochmal Logs:
2016-10-11_06:30:24 BrZi_ErkerLi_Rollo set_on
2016-10-11_06:30:24 BrZi_ErkerMi_Rollo set_on
2016-10-11_06:30:24 BrZi_ErkerRe_Rollo set_on
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo aesKeyNbr: 02
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo RSSI: -72.5
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo RAWMSG: A1119A0024AD281D3AA7804FA36DB6B523002::-72.5:nanoCULHomeMatic
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo aesCommToDev: fail
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo aesKeyNbr: 02
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo RSSI: -72
2016-10-11_06:30:27 BrZi_ErkerLi_Rollo RAWMSG: A1119A0024AD281D3AA78048C0C66F7D32D02::-72:nanoCULHomeMatic
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo aesKeyNbr: 02
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo RAWMSG: A1114A0024AD26BD3AA78048C63AC1D0FFB02::-65.5:nanoCULHomeMatic
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo RSSI: -65.5
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo aesCommToDev: fail
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo aesKeyNbr: 02
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo RSSI: -66
2016-10-11_06:30:27 BrZi_ErkerMi_Rollo RAWMSG: A1114A0024AD26BD3AA7804B1BCC4DA439402::-66:nanoCULHomeMatic
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo aesKeyNbr: 02
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo RAWMSG: A1114A0024AD28CD3AA7804B1BCB206130302::-66:nanoCULHomeMatic
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo RSSI: -66
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo aesCommToDev: ok
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo deviceMsg: zu (to hm_VCCU)
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo level: 0
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo motor: up:zu
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo pct: 0
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo zu
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo timedOn: zu
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo RSSI: -65.5
2016-10-11_06:30:28 BrZi_ErkerRe_Rollo RAWMSG: A121480024AD28CD3AA780101001042BAC8748F::-65.5:nanoCULHomeMatic
2016-10-11_06:30:58 BrZi_ErkerLi_Rollo ResndFail
2016-10-11_06:30:58 BrZi_ErkerLi_Rollo MISSING ACK
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo deviceMsg: auf (to hm_VCCU)
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo level: 100
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo motor: stop:auf
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo pct: 100
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo auf
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo timedOn: zu
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-64:nanoCULHomeMatic
2016-10-11_06:31:10 BrZi_ErkerRe_Rollo RSSI: -64
2016-10-11_06:31:16 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-64:nanoCULHomeMatic
2016-10-11_06:31:16 BrZi_ErkerRe_Rollo RSSI: -64
2016-10-11_06:31:17 BrZi_ErkerRe_Rollo RSSI: -65.5
2016-10-11_06:31:17 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-65.5:nanoCULHomeMatic
2016-10-11_06:31:26 BrZi_ErkerRe_Rollo RSSI: -66
2016-10-11_06:31:26 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-66:nanoCULHomeMatic
2016-10-11_06:31:27 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-65.5:nanoCULHomeMatic
2016-10-11_06:31:27 BrZi_ErkerRe_Rollo RSSI: -65.5
2016-10-11_06:31:33 BrZi_ErkerRe_Rollo RAWMSG: A0D15A4104AD28CD3AA780601C800::-65:nanoCULHomeMatic
2016-10-11_06:31:33 BrZi_ErkerRe_Rollo RSSI: -65
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo deviceMsg: 10 (to hm_VCCU)
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo level: 10
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo motor: up:10
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo pct: 10
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo 10
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo timedOn: zu
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo RAWMSG: A0D16A4104AD26BD3AA7806011410::-65:nanoCULHomeMatic
2016-10-11_06:31:48 BrZi_ErkerMi_Rollo RSSI: -65
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo deviceMsg: 8.5 (to hm_VCCU)
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo level: 8.5
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo motor: up:8.5
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo pct: 8.5
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo 8.5
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo timedOn: zu
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo RAWMSG: A0D1BA4104AD281D3AA7806011110::-75.5:nanoCULHomeMatic
2016-10-11_06:31:50 BrZi_ErkerLi_Rollo RSSI: -75.5
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo deviceMsg: auf (to hm_VCCU)
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo level: 100
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo motor: stop:auf
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo pct: 100
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo auf
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo timedOn: zu
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo RSSI: -65
2016-10-11_06:32:19 BrZi_ErkerMi_Rollo RAWMSG: A0D17A4104AD26BD3AA780601C800::-65:nanoCULHomeMatic
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo deviceMsg: auf (to hm_VCCU)
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo level: 100
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo motor: stop:auf
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo pct: 100
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo auf
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo timedOn: zu
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo RAWMSG: A0D1CA4104AD281D3AA780601C800::-71:nanoCULHomeMatic
2016-10-11_06:32:21 BrZi_ErkerLi_Rollo RSSI: -71
2016-10-11_06:32:23 BrZi_ErkerLi_Rollo RSSI: -78
2016-10-11_06:32:23 BrZi_ErkerLi_Rollo RAWMSG: A0D1CA4104AD281D3AA780601C800::-78:nanoCULHomeMatic
2016-10-11_06:32:23 BrZi_ErkerMi_Rollo RAWMSG: A0D17A4104AD26BD3AA780601C800::-65.5:nanoCULHomeMatic
2016-10-11_06:32:23 BrZi_ErkerMi_Rollo RSSI: -65.5
2016-10-11_06:32:28 BrZi_ErkerLi_Rollo RAWMSG: A0D1CA4104AD281D3AA780601C800::-76:nanoCULHomeMatic
2016-10-11_06:32:28 BrZi_ErkerLi_Rollo RSSI: -76

Hier ist BrZi_ErkerRe_Rollo losgelaufen, die anderen beiden nicht. Am Ende habe ich ..Mi.. und ..Li.. manuell hochfahren lassen.

Viele Grüße,
Christian

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #244 am: 11 Oktober 2016, 21:03:51 »
Hallo Christian,

dann stell bitte mal den NanoCUL auf verbose=4 und schicke ein List.

Wenn Rudolf nicht noch was eingebaut hat, um den verbose zu überschreiben, oder Du nicht noch Log Filter gesetzt hast, mit denen ausschließlich Deine Rolladen geloggt werden, dann kann das nicht sein.

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #245 am: 11 Oktober 2016, 21:20:39 »
Hallo Ansgar!

Habe jetzt wieder auf die Standardmodule und die culfw 1.66 zurückgestellt. Da sich das Logging damit aber ganauso verhält hoffe ich, dass der List auch so hilft.

Hier der HM CUL:
Internals:
   CMDS       BCFiAZEkGMKUYRTVWXefltx
   Clients    :CUL_HM:HMS:CUL_IR:STACKABLE_CC:
   DEF        /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A700CTOG-if00-port0@38400 0000
   DeviceName /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A700CTOG-if00-port0@38400
   FD         14
   FHTID      0000
   NAME       nanoCULHomeMatic
   NR         37
   NR_CMD_LAST_H 82
   PARTIAL
   RAWMSG     A1957A6034C1AFAD3AA78EA2B4726493C4187276E593029F8B904DF
   RSSI       -90.5
   STATE      Initialized
   TYPE       CUL
   VERSION    V 1.66 nanoCUL868
   initString X21
Ar
   nanoCULHomeMatic_MSGCNT 40
   nanoCULHomeMatic_TIME 2016-10-11 21:10:29
   owner_CCU  hm_VCCU
   Matchlist:
     1:CUL_HM   ^A....................
     8:HMS      ^810e04....(1|5|9).a001
     D:CUL_IR   ^I............
     H:STACKABLE_CC ^\*
   Readings:
     2016-10-10 18:44:02   Xmit-Events     Warning-HighLoad:1 init:2 disconnected:1 ok:1 ERROR-Overload:1
     2016-09-09 13:30:35   ccconf          freq:868.300MHz bWidth:101KHz rAmpl:33dB sens:8dB
     2016-10-11 20:21:03   cmds             B C F i A Z E k G M K U Y R T V W X e f l t x
     2016-10-10 18:44:02   cond            ok
     2016-10-10 18:53:24   credit10ms      1014
     2016-10-10 18:52:37   hmSioDly        -1
     2016-10-10 18:34:36   prot_ERROR-Overload last
     2016-10-10 18:30:49   prot_Warning-HighLoad last
     2016-10-10 18:30:16   prot_disconnected last
     2016-10-10 18:30:17   prot_init       last
     2016-10-10 18:44:02   prot_ok         last
     2016-10-09 19:49:02   scF             0.999757851177839
     2016-10-11 21:10:29   state           Initialized
     2016-05-18 08:13:12   uptime          0 07:00:34
   XMIT_TIME:
     1476210090.65173
     1476210093.03576
     1476210093.36646
     1476210093.65502
     1476210095.26687
     1476210096.57788
     1476210097.771
     1476210098.69266
     1476210099.04996
     1476210099.24718
     1476210100.14954
     1476210100.34165
     1476210101.24277
     1476210101.43332
     1476210102.32497
     1476210102.56924
     1476210103.40789
     1476210103.59809
     1476210104.47128
     1476210104.66581
     1476210105.49168
     1476210106.03597
     1476210106.51094
     1476210107.5741
     1476210110.04813
     1476210111.4129
     1476210111.79988
     1476210112.08234
     1476210112.86842
     1476210113.21231
     1476210113.89919
     1476210114.12494
     1476210114.96332
     1476210115.49594
     1476210115.72205
     1476210115.75459
     1476210116.0268
     1476210117.01239
     1476210117.2861
     1476210117.81865
     1476210118.34395
     1476210122.59142
     1476210122.69679
     1476210122.84702
     1476210122.86148
     1476210123.05078
     1476210123.15595
     1476210123.34827
     1476210123.90649
     1476210124.43941
     1476210125.18106
     1476210125.71295
     1476210126.20156
     1476210126.38355
     1476210127.93746
     1476210128.7794
     1476210129.03478
     1476210129.24581
     1476210133.35166
     1476210138.2797
     1476210142.67944
     1476210147.722
     1476211927.73372
     1476211929.82924
     1476211931.40335
     1476211932.94479
     1476211935.65266
     1476211935.83206
     1476211937.48538
     1476211938.29023
     1476211938.39938
     1476211938.57627
     1476211942.91213
     1476211943.56986
     1476211943.64505
     1476211943.82167
     1476211949.22097
     1476211949.39789
     1476212261.56258
     1476213029.15197
     1476213029.42199
     1476213029.72346
   Helper:
     0a0301:
       QUEUE:
     0a0302:
       QUEUE:
     35f3dc:
       QUEUE:
     361e23:
       QUEUE:
     3f86f8:
       QUEUE:
     42250a:
       QUEUE:
     4569c9:
       QUEUE:
     4569d2:
       QUEUE:
     481c40:
       QUEUE:
     4ab1b6:
       QUEUE:
     4ad222:
       QUEUE:
     4ad26b:
       QUEUE:
     4ad279:
       QUEUE:
     4ad27a:
       QUEUE:
     4ad281:
       QUEUE:
     4ad28c:
       QUEUE:
     4ad2c0:
       QUEUE:
     4b29d6:
       QUEUE:
     4c1afa:
       QUEUE:
Attributes:
   addvaltrigger 1
   devStateIcon Initialized:usb@green Open:usb@red
   hmId       D3AA78
   model      nanoCUL
   rfmode     HomeMatic
   verbose    4

...und hier zur Sicherheit nochmal ein Aktor:

Internals:
   DEF        4AD26B
   IODev      nanoCULHomeMatic
   LASTInputDev nanoCULHomeMatic
   MSGCNT     1
   NAME       BrZi_ErkerMi_Rollo
   NOTIFYDEV  global
   NR         291
   NTFY_ORDER 50-BrZi_ErkerMi_Rollo
   STATE      zu
   TYPE       CUL_HM
   lastMsg    No:02 - t:10 s:4AD26B d:D3AA78 0601000042
   nanoCULHomeMatic_MSGCNT 1
   nanoCULHomeMatic_RAWMSG A0E02A4104AD26BD3AA780601000042::-62.5:nanoCULHomeMatic
   nanoCULHomeMatic_RSSI -62.5
   nanoCULHomeMatic_TIME 2016-10-11 20:21:39
   protLastRcv 2016-10-11 20:21:39
   protSnd    2 last_at:2016-10-11 20:21:39
   protState  CMDs_done
   rssi_at_nanoCULHomeMatic lst:-62.5 avg:-62.5 cnt:1 min:-62.5 max:-62.5
   rssi_nanoCULHomeMatic min:-66 max:-66 cnt:1 avg:-66 lst:-66
   Readings:
     2016-10-11 19:47:00   D-firmware      2.8
     2016-10-11 19:47:00   D-serialNr      NEQ0394531
     2016-10-11 19:47:45   PairedTo        0xD3AA78
     2016-10-11 19:47:47   R-driveDown     27 s
     2016-10-11 19:47:47   R-driveTurn     0.5 s
     2016-10-11 19:47:47   R-driveUp       28 s
     2016-10-11 19:47:45   R-pairCentral   0xD3AA78
     2016-10-11 19:47:47   R-sign          on
     2016-10-11 19:47:45   RegL_00.        02:01 0A:D3 0B:AA 0C:78 15:FF 18:00 00:00
     2016-10-11 19:47:47   RegL_01.        08:01 09:00 0A:00 0B:01 0C:0E 0D:01 0E:18 0F:05 10:00  30:06 57:24 56:00 00:00
     2016-10-11 20:21:39   deviceMsg       off (to hm_VCCU)
     2016-10-11 20:21:39   level           0
     2016-10-11 20:21:39   motor           stop:off
     2016-10-11 20:21:39   pct             0
     2016-10-11 20:21:39   recentStateType info
     2016-10-11 20:21:39   state           off
     2016-10-11 20:21:39   timedOn         off
   Helper:
     HM_CMDNR   2
     cSnd       ,01D3AA784AD26B010E
     mId        006A
     rxType     1
     Dir:
       cur        stop
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       newChn     +4AD26B,00,01,00
       nextSend   1476210099.33076
       rxt        0
       vccu       hm_VCCU
       p:
         4AD26B
         00
         01
         00
       prefIO:
         nanoCULHomeMatic
     Mrssi:
       mNo        02
       Io:
         nanoCULHomeMatic -60.5
     Prt:
       bErr       0
       sProc      0
       Rspwait:
     Q:
       qReqConf
       qReqStat
     Role:
       chn        1
       dev        1
       prs        1
     Rpt:
       IO         nanoCULHomeMatic
       flg        A
       ts         1476210099.24605
       ack:
         HASH(0x3935160)
         028002D3AA784AD26B00
     Rssi:
       At_nanoculhomematic:
         avg        -62.5
         cnt        1
         lst        -62.5
         max        -62.5
         min        -62.5
       Nanoculhomematic:
         avg        -66
         cnt        1
         lst        -66
         max        -66
         min        -66
     Shadowreg:
     Tmpl:
Attributes:
   IODev      nanoCULHomeMatic
   IOgrp      hm_VCCU:nanoCULHomeMatic
   alias      Bar Mitte
   autoReadReg 4_reqStatus
   devStateIcon auf:fts_shutter_10:zu zu:fts_shutter_100:auf
   eventMap   on:auf off:zu
   expert     2_raw
   firmware   2.8
   group      Rollläden
   isSleepingRoom 0
   model      HM-LC-Bl1PBU-FM
   peerIDs    00000000,
   room       Barzimmer
   serialNr   NEQ0394531
   subType    blindActuator
   userattr   isSleepingRoom
   webCmd     auf:zu:stop:pct


Viele Grüße,
Christian

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #246 am: 11 Oktober 2016, 21:44:11 »
Habe jetzt gerade zur Sicherheit nochmal über das Eventlog geprüft: Der CUL taucht auch hier nicht auf, nur der Aktor.

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #247 am: 11 Oktober 2016, 22:02:54 »
Hallo Christian,

und wie ziehst Du das Log?

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #248 am: 11 Oktober 2016, 22:14:43 »
Für den Aktor hiermit:

Internals:
   DEF        /var/log/fhem/Rollos-%Y-%m.log ...._.*Rollo|ScZi_Rollo.*
   NAME       log_Rollos
   NR         233
   NTFY_ORDER 50-log_Rollos
   REGEXP     ...._.*Rollo|ScZi_Rollo.*
   STATE      active
   TYPE       FileLog
   currentlogfile /var/log/fhem/Rollos-2016-10.log
   logfile    /var/log/fhem/Rollos-%Y-%m.log
   Readings:
     2016-10-11 21:53:20   linesInTheFile  12804
Attributes:
   archiveCompress 1
   archivedir /var/log/fhem/archive
   logtype    text
   nrarchive  0

...und für die CULs so:

Internals:
   DEF        /var/log/fhem/log_CUL-%Y-%m.log nanoCUL.*|hm_VCCU
   NAME       log_CUL
   NR         317
   NTFY_ORDER 50-log_CUL
   REGEXP     nanoCUL.*|hm_VCCU
   STATE      active
   TYPE       FileLog
   currentlogfile /var/log/fhem/log_CUL-2016-10.log
   logfile    /var/log/fhem/log_CUL-%Y-%m.log
   Readings:
     2016-10-11 22:06:14   linesInTheFile  475
Attributes:
   archiveCompress 1
   archivedir /var/log/fhem/archive
   nrarchive  0

Wie gesagt, im Eventlog habe ich für die letzte Aktion auch nochmal gegengeprüft.

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #249 am: 11 Oktober 2016, 22:31:01 »
Hallo Christian,

ok, da haben wir das Verständnisproblem.

Was Du so "loggst" sind notifies etc. aber nicht die Log Ausgabe aus dem Code, die interessiert.

Außerdem solltedt Du noch das globale Attribut
attr global mseclog 1 setzen, damit die Zeiten um die ms ergänzt geloggt werden.

Klick doch im Browser bei FHEM mal links auf "Logfile" ... da findest Du die interessanten Log Einträge.

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #250 am: 11 Oktober 2016, 22:39:36 »
Hi Ansgar!

Ok, danke dir!
Ich sehe mir gleich noch mein Logfile an. Wenn ich aber wieder auf deine Module gehen muss, um die Logs zu erzeugen, dann wird es verm. Wo-Ende werden. Bin ab morgen unterwegs.


Vielen Dank bis dahin,
Christian

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #251 am: 11 Oktober 2016, 22:53:25 »
Hallo Christian,

Zitat
Wenn ich aber wieder auf deine Module gehen muss, um die Logs zu erzeugen
ja, und auch auf die TS Firmware  ;)

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #252 am: 16 Oktober 2016, 15:57:47 »
Hallo Ansgar!

Sorry, hat etwas bei mir gedauert.

Test: Es wurden 3 Rollläden gleichzeit angesteuert. Davon hat einer reagiert, die anderen beiden nicht.

Hier das Logfile (CUL auf verbose 4):
2016.10.16 15:47:11.876 4: TSCUL_Parse: nanoCULHomeMatic  461427 A FFB2 00180816 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:47:45.213 4: TSCUL_Parse: nanoCULHomeMatic  494764 A FFA2 00214168 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:48:18.119 4: TSCUL_Parse: nanoCULHomeMatic  003382 A FFA2 00247080 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:48:52.290 4: TSCUL_Parse: nanoCULHomeMatic  037551 A FFA2 00281256 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:49:06.873 3: CUL_HM set BrZi_ErkerLi_Rollo on
2016.10.16 15:49:06.886 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD281 0201C80000
2016.10.16 15:49:06.983 3: CUL_HM set BrZi_ErkerRe_Rollo on
2016.10.16 15:49:07.024 4: TSCUL_Parse: nanoCULHomeMatic  052293 A FF93 00295872 00 0E 03 A011 D3AA78 4AD281  -138
2016.10.16 15:49:08.555 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD281 0201C80000
2016.10.16 15:49:08.560 4: TSCUL_Parse: nanoCULHomeMatic  053825 A FF91 00296032 00 11 03 A002 4AD281 D3AA78 044C00E75D457A02 -74
2016.10.16 15:49:08.637 4: TSCUL_Parse: nanoCULHomeMatic  053906 A FF93 00297544 00 0E 03 A011 D3AA78 4AD281  -138
2016.10.16 15:49:08.697 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD281 d435475d7cb75a883f4daad7a11c37fe
2016.10.16 15:49:08.759 4: TSCUL_Parse: nanoCULHomeMatic  054027 A FF93 00297696 00 19 03 A003 D3AA78 4AD281  -138
2016.10.16 15:49:08.773 4: TSCUL_Parse: nanoCULHomeMatic  054037 A FF91 00297736 00 11 03 A002 4AD281 D3AA78 04E9D4AF043EE202 -74
2016.10.16 15:49:08.790 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD281 6b4c6772d33d9afb68960c70ead358d0
2016.10.16 15:49:08.864 4: TSCUL_Parse: nanoCULHomeMatic  054133 A FF93 00297784 00 19 03 A003 D3AA78 4AD281  -138
2016.10.16 15:49:09.979 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD281 6b4c6772d33d9afb68960c70ead358d0
2016.10.16 15:49:10.565 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD26B 0201C80000
2016.10.16 15:49:10.893 4: TSCUL_Parse: nanoCULHomeMatic  056162 A FFA3 00298976 00 19 03 A003 D3AA78 4AD281  -138
2016.10.16 15:49:10.895 4: TSCUL_Parse: nanoCULHomeMatic  056164 A FFA3 00299552 00 0E 03 A011 D3AA78 4AD26B  -138
2016.10.16 15:49:10.898 4: TSCUL_Parse: nanoCULHomeMatic  056162 A FFA1 00299712 00 11 03 A002 4AD26B D3AA78 04ED331477AB5902 -67
2016.10.16 15:49:10.914 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD26B a98816e4496e6f6d8465f195e82ced28
2016.10.16 15:49:11.044 4: TSCUL_Parse: nanoCULHomeMatic  056312 A FFA3 00299912 00 19 03 A003 D3AA78 4AD26B  -138
2016.10.16 15:49:11.343 4: TSCUL_send:  nanoCULHomeMatic                    Aa 9276 19 03 A003 D3AA78 4AD26B a98816e4496e6f6d8465f195e82ced28
2016.10.16 15:49:11.344 3: TSCUL_XmitDlyHM:  nanoCULHomeMatic  id:4AD26B dDly:-389 tgtDly:240 toms:17
2016.10.16 15:49:11.581 4: TSCUL_Parse: nanoCULHomeMatic  056845 A FFA1 00300064 00 12 03 8002 4AD26B D3AA78 01012C1046A6083404 -66.5
2016.10.16 15:49:11.601 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD28C 0201C80000
2016.10.16 15:49:11.717 3: TSCUL_ParseTsHM: nanoCULHomeMatic  id:4AD26B dhmSt:632 dHMtgt:240
2016.10.16 15:49:11.718 4: TSCUL_Parse: nanoCULHomeMatic  056986 A FFA3 00300344 00 19 03 A003 D3AA78 4AD26B  -138
2016.10.16 15:49:11.723 4: TSCUL_Parse: nanoCULHomeMatic  056992 A FFA3 00300592 00 0E 03 A011 D3AA78 4AD28C  -138
2016.10.16 15:49:17.567 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD28C 0201C80000
2016.10.16 15:49:17.569 4: CUL_HM_Resend: BrZi_ErkerRe_Rollo nr 2
2016.10.16 15:49:19.107 4: TSCUL_Parse: nanoCULHomeMatic  064372 A FFA1 00300744 00 11 03 A002 4AD28C D3AA78 0423FCBBFBD2E102 -70
2016.10.16 15:49:19.187 4: TSCUL_Parse: nanoCULHomeMatic  064456 A FFA3 00306560 00 0E 03 A011 D3AA78 4AD28C  -138
2016.10.16 15:49:19.189 4: TSCUL_Parse: nanoCULHomeMatic  064454 A FFA1 00306712 00 11 03 A002 4AD28C D3AA78 042CB07E0F7E0102 -68
2016.10.16 15:49:19.193 1: PERL WARNING: Use of uninitialized value $parse in string eq at ./FHEM/10_CUL_HM.pm line 1347.
2016.10.16 15:49:19.194 1: PERL WARNING: Use of uninitialized value $parse in string eq at ./FHEM/10_CUL_HM.pm line 1348.
2016.10.16 15:49:19.194 1: PERL WARNING: Use of uninitialized value $parse in string eq at ./FHEM/10_CUL_HM.pm line 1351.
2016.10.16 15:49:19.195 1: PERL WARNING: Use of uninitialized value $parse in string eq at ./FHEM/10_CUL_HM.pm line 1355.
2016.10.16 15:49:19.195 1: PERL WARNING: Use of uninitialized value $parse in string eq at ./FHEM/10_CUL_HM.pm line 1358.
2016.10.16 15:49:19.288 4: TSCUL_send:  nanoCULHomeMatic                         As 0E 03 A011 D3AA78 4AD28C 0201C80000
2016.10.16 15:49:19.464 4: TSCUL_Parse: nanoCULHomeMatic  064733 A FFA3 00308280 00 0E 03 A011 D3AA78 4AD28C  -138
2016.10.16 15:49:19.478 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD28C 1e786947479e2912045cab5f279b4ea7
2016.10.16 15:49:19.479 4: TSCUL_Parse: nanoCULHomeMatic  064731 A FFA1 00308432 00 11 03 A002 4AD28C D3AA78 044504D76F4C5102 -67
2016.10.16 15:49:19.559 4: TSCUL_Parse: nanoCULHomeMatic  064827 A FFA3 00308480 00 19 03 A003 D3AA78 4AD28C  -138
2016.10.16 15:49:19.830 4: TSCUL_send:  nanoCULHomeMatic                         As 19 03 A003 D3AA78 4AD28C 1e786947479e2912045cab5f279b4ea7
2016.10.16 15:49:19.856 4: TSCUL_send:  nanoCULHomeMatic                         As 0A 03 8002 D3AA78 4AD28C 00
2016.10.16 15:49:19.881 4: TSCUL_send:  nanoCULHomeMatic                         As 0A 03 8002 D3AA78 4AD28C 00
2016.10.16 15:49:19.885 4: TSCUL_Parse: nanoCULHomeMatic  065154 A FFA3 00308832 00 19 03 A003 D3AA78 4AD28C  -138
2016.10.16 15:49:19.911 4: TSCUL_Parse: nanoCULHomeMatic  065180 A FFA3 00308864 00 0A 03 8002 D3AA78 4AD28C  -138
2016.10.16 15:49:19.936 4: TSCUL_Parse: nanoCULHomeMatic  065205 A FFA3 00308896 00 0A 03 8002 D3AA78 4AD28C  -138
2016.10.16 15:49:22.682 4: TSCUL_Parse: nanoCULHomeMatic  067945 A FFA2 00311656 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:49:37.778 4: TSCUL_Parse: nanoCULHomeMatic  083044 A FFA1 00326744 00 0D 04 A410 4AD26B D3AA78 0601C800 -66
2016.10.16 15:49:37.797 4: TSCUL_send:  nanoCULHomeMatic                      Aw 0B 0A 04 8002 D3AA78 4AD26B 00
2016.10.16 15:49:37.798 3: TSCUL_XmitDlyHM:  nanoCULHomeMatic  id:4AD26B dDly:85 tgtDly:120 toms:99
2016.10.16 15:49:38.028 3: TSCUL_ParseTsHM: nanoCULHomeMatic  id:4AD26B dhmSt:136 dHMtgt:120 hmSioDly:-1
2016.10.16 15:49:38.029 4: TSCUL_Parse: nanoCULHomeMatic  083296 A FFA3 00326880 00 0A 04 8002 D3AA78 4AD26B  -138
2016.10.16 15:49:54.968 4: TSCUL_Parse: nanoCULHomeMatic  100231 A FF92 00343952 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:50:28.621 4: TSCUL_Parse: nanoCULHomeMatic  133883 A FF92 00377616 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:50:58.798 4: TSCUL_Parse: nanoCULHomeMatic  164060 A FF92 00407800 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:51:31.926 4: TSCUL_Parse: nanoCULHomeMatic  197188 A FF92 00440928 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:52:06.065 4: TSCUL_Parse: nanoCULHomeMatic  231328 A FF92 00475080 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138
2016.10.16 15:52:38.817 4: TSCUL_Parse: nanoCULHomeMatic  264079 A FF92 00507840 00 15 AABBCCDDAABBCCDDAABBCCDDAABBCCDDAABBCCDDAA -138

List BrZi_ErkerLi_Rollo (ist auf Fehler gelaufen)
Internals:
   DEF        4AD281
   IODev      nanoCULHomeMatic
   LASTInputDev nanoCULHomeMatic
   MSGCNT     3
   NAME       BrZi_ErkerLi_Rollo
   NOTIFYDEV  global
   NR         290
   NTFY_ORDER 50-BrZi_ErkerLi_Rollo
   STATE      set_on
   TYPE       CUL_HM
   lastMsg    No:03 - t:02 s:4AD281 d:D3AA78 04E9D4AF043EE202
   nanoCULHomeMatic_MSGCNT 3
   nanoCULHomeMatic_RAWMSG A1103A0024AD281D3AA7804E9D4AF043EE202::-74:nanoCULHomeMatic
   nanoCULHomeMatic_RSSI -74
   nanoCULHomeMatic_TIME 2016-10-16 15:49:08
   protLastRcv 2016-10-16 15:49:08
   protSnd    5 last_at:2016-10-16 15:49:08
   protState  CMDs_processing...
   rssi_at_nanoCULHomeMatic avg:-74 lst:-74 max:-74 cnt:3 min:-74
   rssi_nanoCULHomeMatic lst:-73 avg:-73 max:-73 min:-73 cnt:1
   Readings:
     2016-10-16 10:38:32   CommandAccepted yes
     2016-10-11 19:47:00   D-firmware      2.8
     2016-10-11 19:47:00   D-serialNr      NEQ0394497
     2016-10-11 19:47:40   PairedTo        0xD3AA78
     2016-10-11 19:47:41   R-driveDown     27 s
     2016-10-11 19:47:41   R-driveTurn     0.5 s
     2016-10-11 19:47:41   R-driveUp       28 s
     2016-10-11 19:47:40   R-pairCentral   0xD3AA78
     2016-10-11 19:47:41   R-sign          on
     2016-10-11 19:47:40   RegL_00.        02:01 0A:D3 0B:AA 0C:78 15:FF 18:00 00:00
     2016-10-11 19:47:41   RegL_01.        08:01 09:00 0A:00 0B:01 0C:0E 0D:01 0E:18 0F:05 10:00  30:06 57:24 56:00 00:00
     2016-10-16 15:49:08   aesCommToDev    fail
     2016-10-16 15:49:08   aesKeyNbr       02
     2016-10-16 15:45:52   deviceMsg       79.5 (to hm_VCCU)
     2016-10-16 15:45:52   level           79.5
     2016-10-16 15:45:52   motor           stop:79.5
     2016-10-16 15:45:52   pct             79.5
     2016-10-16 15:45:52   recentStateType info
     2016-10-16 15:49:06   state           set_on
     2016-10-16 15:45:52   timedOn         off
   cmdStack:
   Helper:
     AESreqAck  25E2C0D2
     HM_CMDNR   3
     cSnd       01D3AA784AD281010E,11D3AA784AD2810201C80000
     dlvl       C8
     dlvlCmd    ++A011D3AA784AD2810201C80000
     mId        006A
     rxType     1
     supp_Pair_Rep 0
     Dir:
       cur        stop
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       dwoCAAa    192
       lRcTm      296032
       lstRecType 02
       lstSnd     1476625747.15952
       lstSndTgd  360
       newChn     +4AD281,00,01,00
       nextSend   1476625747.15952
       nxtSndMcnt 03
       rxt        0
       tgtDly     120
       vccu       hm_VCCU
       p:
         4AD281
         00
         01
         00
       prefIO:
         nanoCULHomeMatic
     Mrssi:
       mNo        03
       Io:
         nanoCULHomeMatic -72
     Prt:
       bErr       0
       sProc      1
     Q:
       qReqConf
       qReqStat
     Role:
       chn        1
       dev        1
       prs        1
     Rssi:
       At_nanoculhomematic:
         avg        -74
         cnt        3
         lst        -74
         max        -74
         min        -74
       Nanoculhomematic:
         avg        -73
         cnt        1
         lst        -73
         max        -73
         min        -73
     Tmpl:
Attributes:
   IODev      nanoCULHomeMatic
   IOgrp      hm_VCCU:nanoCULHomeMatic
   alias      Bar Links
   autoReadReg 4_reqStatus
   devStateIcon auf:fts_shutter_10:zu zu:fts_shutter_100:auf
   eventMap   on:auf off:zu
   expert     2_raw
   firmware   2.8
   group      Rollläden
   isSleepingRoom 0
   model      HM-LC-Bl1PBU-FM
   peerIDs    00000000,
   room       Barzimmer
   serialNr   NEQ0394497
   subType    blindActuator
   userattr   isSleepingRoom
   verbose    4
   webCmd     auf:zu:stop:pct

List BrZi_ErkerRe_Rollo (ist auf Fehler gelaufen)
Internals:
   DEF        4AD28C
   IODev      nanoCULHomeMatic
   LASTInputDev nanoCULHomeMatic
   MSGCNT     6
   NAME       BrZi_ErkerRe_Rollo
   NOTIFYDEV  global
   NR         292
   NTFY_ORDER 50-BrZi_ErkerRe_Rollo
   STATE      set_on
   TYPE       CUL_HM
   lastMsg    No:03 - t:02 s:4AD28C d:D3AA78 044504D76F4C5102
   nanoCULHomeMatic_MSGCNT 6
   nanoCULHomeMatic_RAWMSG A1103A0024AD28CD3AA78044504D76F4C5102::-67:nanoCULHomeMatic
   nanoCULHomeMatic_RSSI -67
   nanoCULHomeMatic_TIME 2016-10-16 15:49:19
   protLastRcv 2016-10-16 15:49:19
   protResnd  2 last_at:2016-10-16 15:49:17
   protSnd    7 last_at:2016-10-16 15:49:19
   protState  CMDs_done
   rssi_at_nanoCULHomeMatic cnt:6 min:-70 max:-67 avg:-68.91 lst:-67
   rssi_nanoCULHomeMatic lst:-69 avg:-69 max:-69 min:-69 cnt:1
   Readings:
     2016-10-16 10:26:12   CommandAccepted yes
     2016-10-11 19:47:00   D-firmware      2.8
     2016-10-11 19:47:00   D-serialNr      NEQ0394501
     2016-10-11 18:51:21   PairedTo        0xD3AA78
     2016-10-11 18:51:34   R-driveDown     27 s
     2016-10-11 18:51:34   R-driveTurn     0.5 s
     2016-10-11 18:51:34   R-driveUp       28 s
     2016-10-11 18:51:21   R-pairCentral   0xD3AA78
     2016-10-11 18:51:34   R-sign          on
     2016-10-11 18:51:21   RegL_00.        02:01 0A:D3 0B:AA 0C:78 15:FF 18:00 00:00
     2016-10-11 18:51:34   RegL_01.        08:01 09:00 0A:00 0B:01 0C:0E 0D:01 0E:18 0F:05 10:00  30:06 57:24 56:00 00:00
     2016-10-16 15:49:19   aesCommToDev    fail
     2016-10-16 15:49:19   aesKeyNbr       02
     2016-10-16 15:46:02   deviceMsg       12.5 (to hm_VCCU)
     2016-10-16 15:46:02   level           12.5
     2016-10-16 15:46:02   motor           stop:12.5
     2016-10-16 15:46:02   pct             12.5
     2016-10-16 15:46:02   recentStateType info
     2016-10-16 15:49:06   state           set_on
     2016-10-16 15:46:02   timedOn         off
   Helper:
     HM_CMDNR   3
     cSnd       01D3AA784AD28C010E,11D3AA784AD28C0201C80000
     dlvl       C8
     dlvlCmd    ++A011D3AA784AD28C0201C80000
     mId        006A
     rxType     1
     supp_Pair_Rep 0
     Dir:
       cur        stop
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       lRcTm      300744
       lstRecType 02
       lstSnd     1476625751.87087
       lstSndTgd  600
       newChn     +4AD28C,00,01,00
       nextSend   1476625751.87087
       nxtSndMcnt 03
       rxt        0
       tgtDly     120
       vccu       hm_VCCU
       p:
         4AD28C
         00
         01
         00
       prefIO:
         nanoCULHomeMatic
     Mrssi:
       mNo        03
       Io:
         nanoCULHomeMatic -65
     Prt:
       bErr       0
       sProc      0
       Rspwait:
     Q:
       qReqConf
       qReqStat
     Role:
       chn        1
       dev        1
       prs        1
     Rpt:
       IO         nanoCULHomeMatic
       flg        A
       ts         1476625759.48423
       ack:
         HASH(0x3def530)
         038002D3AA784AD28C00
     Rssi:
       At_nanoculhomematic:
         avg        -68.9166666666667
         cnt        6
         lst        -67
         max        -67
         min        -70
       Nanoculhomematic:
         avg        -69
         cnt        1
         lst        -69
         max        -69
         min        -69
     Tmpl:
Attributes:
   IODev      nanoCULHomeMatic
   IOgrp      hm_VCCU:nanoCULHomeMatic
   alias      Bar Rechts
   autoReadReg 4_reqStatus
   devStateIcon auf:fts_shutter_10:zu zu:fts_shutter_100:auf
   eventMap   on:auf off:zu
   expert     2_raw
   firmware   2.8
   group      Rollläden
   isSleepingRoom 0
   model      HM-LC-Bl1PBU-FM
   peerIDs    00000000,
   room       Barzimmer
   serialNr   NEQ0394501
   subType    blindActuator
   userattr   isSleepingRoom
   verbose    4
   webCmd     auf:zu:stop:pct

List BrZi_ErkerMi_Rollo (ist korrekt gelaufen)
Internals:
   DEF        4AD26B
   IODev      nanoCULHomeMatic
   LASTInputDev nanoCULHomeMatic
   MSGCNT     4
   NAME       BrZi_ErkerMi_Rollo
   NOTIFYDEV  global
   NR         291
   NTFY_ORDER 50-BrZi_ErkerMi_Rollo
   STATE      auf
   TYPE       CUL_HM
   lastMsg    No:04 - t:10 s:4AD26B d:D3AA78 0601C800
   nanoCULHomeMatic_MSGCNT 4
   nanoCULHomeMatic_RAWMSG A0D04A4104AD26BD3AA780601C800::-66:nanoCULHomeMatic
   nanoCULHomeMatic_RSSI -66
   nanoCULHomeMatic_TIME 2016-10-16 15:49:37
   protLastRcv 2016-10-16 15:49:37
   protSnd    5 last_at:2016-10-16 15:49:37
   protState  CMDs_done
   rssi_at_nanoCULHomeMatic max:-66 avg:-66.87 lst:-66 cnt:4 min:-68
   rssi_nanoCULHomeMatic cnt:2 min:-72 max:-70 avg:-71 lst:-70
   Readings:
     2016-10-16 15:49:11   CommandAccepted yes
     2016-10-11 19:47:00   D-firmware      2.8
     2016-10-11 19:47:00   D-serialNr      NEQ0394531
     2016-10-16 10:37:50   PairedTo        0xD3AA78
     2016-10-11 19:47:47   R-driveDown     27 s
     2016-10-11 19:47:47   R-driveTurn     0.5 s
     2016-10-11 19:47:47   R-driveUp       28 s
     2016-10-11 19:47:45   R-pairCentral   0xD3AA78
     2016-10-11 19:47:47   R-sign          on
     2016-10-16 10:37:49   RegL_00.        02:01 0A:D3 0B:AA 0C:78 15:FF 18:00 00:00
     2016-10-16 10:37:50   RegL_01.        08:01 09:00 0A:00 0B:01 0C:0E 0D:01 0E:18 0F:05 10:00  30:06 57:24 56:00 00:00
     2016-10-16 15:49:11   aesCommToDev    ok
     2016-10-16 15:49:10   aesKeyNbr       02
     2016-10-16 15:49:37   deviceMsg       on (to hm_VCCU)
     2016-10-16 15:49:37   level           100
     2016-10-16 15:49:37   motor           stop:on
     2016-10-16 15:49:37   pct             100
     2016-10-16 15:49:37   recentStateType info
     2016-10-16 15:49:37   state           on
     2016-10-16 15:49:37   timedOn         off
   Helper:
     HM_CMDNR   4
     cSnd       01D3AA784AD26B010E,11D3AA784AD26B0201C80000
     dlvlCmd    ++A011D3AA784AD26B0201C80000
     mId        006A
     rxType     1
     supp_Pair_Rep 0
     Dir:
       cur        stop
       rct        up
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       dwoCAAa    120
       dwoCAAw    136
       lRcTm      326744
       lstRecType 10
       lstSnd     1476625777.87908
       lstSndTgd  120
       newChn     +4AD26B,00,01,00
       nextSend   1476625777.87908
       nxtSndMcnt 04
       rxt        0
       tgtDly     120
       vccu       hm_VCCU
       p:
         4AD26B
         00
         01
         00
       prefIO:
         nanoCULHomeMatic
     Mrssi:
       mNo        04
       Io:
         nanoCULHomeMatic -64
     Prt:
       bErr       0
       sProc      0
       Rspwait:
     Q:
       qReqConf
       qReqStat
     Role:
       chn        1
       dev        1
       prs        1
     Rpt:
       IO         nanoCULHomeMatic
       flg        A
       ts         1476625777.78562
       ack:
         HASH(0x3def008)
         048002D3AA784AD26B00
     Rssi:
       At_nanoculhomematic:
         avg        -66.875
         cnt        4
         lst        -66
         max        -66
         min        -68
       Nanoculhomematic:
         avg        -71
         cnt        2
         lst        -70
         max        -70
         min        -72
     Tmpl:
Attributes:
   IODev      nanoCULHomeMatic
   IOgrp      hm_VCCU:nanoCULHomeMatic
   alias      Bar Mitte
   autoReadReg 4_reqStatus
   devStateIcon auf:fts_shutter_10:zu zu:fts_shutter_100:auf
   eventMap   on:auf off:zu
   expert     2_raw
   firmware   2.8
   group      Rollläden
   isSleepingRoom 0
   model      HM-LC-Bl1PBU-FM
   peerIDs    00000000,
   room       Barzimmer
   serialNr   NEQ0394531
   subType    blindActuator
   userattr   isSleepingRoom
   verbose    0
   webCmd     auf:zu:stop:pct

List vom CUL
Internals:
   CMDS       ABCEFGJKMRTUVWXYZefilmtx
   Clients    TSSTACKED:STACKABLE_CC:CUL_HM:HMS:CUL_IR
   DEF        /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A700CTOG-if00-port0@38400 0000
   DeviceName /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A700CTOG-if00-port0@38400
   FD         14
   FHTID      0000
   HM_RptCnt  19
   NAME       nanoCULHomeMatic
   NR         37
   PARTIAL
   RAWMSG     AFFA100009F8B000D04A4104AD26BD3AA780601C80010
   RSSI       -66
   STATE      Initialized
   TYPE       TSCUL
   VERSION    V 99.79 nanoCUL868
   VERSION_HW nanoCUL_V1.x
   VERSION_TS yes
   XmitOpen   1
   initString X21
Ar
At1
   nanoCULHomeMatic_MSGCNT 59
   nanoCULHomeMatic_TIME 2016-10-16 15:49:37
   owner_CCU  hm_VCCU
   Matchlist:
     1:TSSTACKED ^\*
     A:CUL_HM   ^A....................
     B:HMS      ^810e04....(1|5|9).a001
     C:CUL_IR   ^I............
   Readings:
     2016-10-16 15:45:49   Xmit-Events     ok:1 disconnected:1 Warning-HighLoad:2 init:2
     2016-09-09 13:30:35   ccconf          freq:868.300MHz bWidth:101KHz rAmpl:33dB sens:8dB
     2016-10-16 15:45:07   cmds             A B C E F G J K M R T U V W X Y Z e f i l m t x
     2016-10-16 15:45:49   cond            Warning-HighLoad
     2016-10-10 18:53:24   credit10ms      1014
     2016-10-16 15:49:38   hmSioDly        -1
     2016-10-10 18:34:36   prot_ERROR-Overload last
     2016-10-16 15:45:49   prot_Warning-HighLoad last
     2016-10-16 15:45:07   prot_disconnected last
     2016-10-16 15:45:08   prot_init       last
     2016-10-16 15:45:48   prot_ok         last
     2016-10-09 19:49:02   scF             0.999757851177839
     2016-10-16 15:45:07   state           Initialized
     2016-05-18 08:13:12   uptime          0 07:00:34
   Helper:
     Devio:
       NDisCon    0
       NRFail     0
       RXfailTS
     Hm:
       FUP        0
       hmCrdts    10
       hmSbusy    0
       lstSndTm   1476625778.01636
       Unknwn:
     Cnd:
       0          1
       2          2
       253        1
       255        2
     Hmq:
     Hmqo:
     Q:
       HMcndN     2
       InQueues   0
       answerPend 0
       hmLanQlen  1
       Cap:
         sum        1000
     Ref:
       Sdly       121
       doNbyterate 78
       hmDstDly   120
       ioByteRate 3840
       ioByteRateMeas 3727.23677838561
       lHMt       308432
       lSys       230751451
       nusew      29
       pTTu       1024
       pndAs      0
       pndCUAp    0
       pngLm      14
       pngMax     -200000
       pngMin     100000000
       pngRef     6
       pngtm      230562232
       pngtmBRs   1476626224.5024
       scF        0.999757851177839
       scFN       0
       scHT       119184
       scST       230562238
Attributes:
   addvaltrigger 1
   devStateIcon Initialized:usb@green Open:usb@red
   hmId       D3AA78
   hmLanQlen  1_min
   model      nanoCUL
   rfmode     HomeMatic
   verbose    4

Viele Grüße,
Christian

Offline noansi

  • Developer
  • Hero Member
  • ****
  • Beiträge: 1310
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #253 am: 16 Oktober 2016, 17:32:47 »
Hallo Christian,

Du hast anscheinend sehr große Verzögerungen im FHEM.

Vermutlich irgendein FHEM Modul braucht sehr viel Zeit am Stück. Ich kenne das bisher von Plots, die beim Neuzeichnen viel Zeit brauchen und dann stören. Oder auch Modul Kommunikation zu Servern mit aktivem Warten auf Antwort, was ganz FHEM anhält.

Mit AES wird das dann fatal, weil Signing Antworten nicht rechtzeitig raus gehen können und Wiederholtimeouts ansprechen, obwohl das device antwortet (aber die Antwort viel zu spät verarbeitet wird). Ohne AES ist es noch unkritisch, weil nicht signiert werden muss.

Um das Problemmodul zu identfizieren müsstest Du Dir eine minimal fhem.cfg bauen in der erst mal nur Homematic mit dem nanoCul und den Rolladen drin ist und dann testen wie es läuft und dann nach und nach weitere Module wieder aktivieren, bis es hakt.

Es gibt natürlich auch noch die Möglichkeit, dass Dein FHEM Rechner zu langsam ist, respektive FHEM vom Betriebssystem her ausgebremst wird. Den Effekt kenne ich von einer sterbenen USB-Festplatte, wo dann die Recoveryversuche von Linux Seite her (USB Resets etc.) zu entsprechenden zeitlichen Störungen geführt haben.
Da gibt das Systemlog ggf. Hinweise.

Gruß, Ansgar.

Offline weini

  • Full Member
  • ***
  • Beiträge: 320
Antw:Firmware zu CUL und Co. mit Timestamp Option ASKSIN Teil1
« Antwort #254 am: 16 Oktober 2016, 20:17:27 »
Hallo Ansgar!

Vielen Dank dir für den Hinweis, in die Richtung kann ich mal weiter forschen.
Ich habe in der Tat fast meinen ganzen Hausstand mittlerweile in FHEM eingebunden. Vom Vorgehen her werde ich erst mal versuchen, meine bestehende Config abzuspecken.

Gibt es vielleicht eine Möglichkeit, Profiling-Daten je Modul zusammeln (ohne dafür die Module umschreiben zu müssen)?

Meine HW sollte schon passen: Ein RasPI 2B auf dem außer FHEM nur noch Pilight läuft. Weder die SD-Karte noch der PI machen laut dmesg und syslog Mucken, das sieht alles in Ordnung aus.

Ich halte dich auf dem Laufenden, was bei der Sache herauskommt.


Viele Grüße,
Christian

 

decade-submarginal