Not enough Credits-Problem

Begonnen von walterschmitz, 17 August 2017, 09:39:25

Vorheriges Thema - Nächstes Thema

walterschmitz

Umgehend nach dem Neustart... mit 38400 Baud...

Habe ich ein Befehl über FHEM an ein Device abgegeben... und erhalte wenige Minuten später
2017.10.29 08:54:40 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 74, but we need 113. Waiting 39 seconds. Currently 1 messages are waiting to be sent.
2017.10.29 08:55:26 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 7, but we need 113. Waiting 106 seconds. Currently 4 messages are waiting to be sent.


Zufall oder was denkst du?
Ich melde mich heute Nachmittag oder Abend noch mal, ob es evtl. besser wird.

Beta-User

Klappt geht ccconf?


Wenn ja: warten, ansonsten zurück und ccconf mit @9600
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

walterschmitz

versteh nicht was du meinst:

bei CCCconf bekomme ich was zurück:
CUL868 ccconf => freq:868.300MHz bWidth:101KHz rAmpl:33dB sens:8dB

also warten, oder?

Beta-User

Wenn eine vernünftige Antwort kommt, stimmt die baud-rate. Also erst mal warten....
Kannst ja mit dem anderen CUL mal testen, ob auch @9600 eine Antwort kommt.
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Beta-User

So, mit einer vernünftigen Tastatur etwas ausführlicher:

Scheinbar wurde die Baud-Rate beim CUL irgendwann geändert auf 38400, ohne dass das irgendwo groß dokumentiert zu sein scheint (nur in der FHEM-Commandref zu CUL finden sich die 38400, ich hatte aber neulich den Fall, dass jemand die 38400 eingestellt hatte, und ich entsprechend commandref bei culfw.de der Ansicht war, das müßte falsch sein, zumal mit firmware 1.61 @9600 noch richtig war/ist)...

Wie dem auch sei: Wenn vom CUL eine sinnvolle Antwort zurückkommt, ist die Baudate ok, die falsche Baudrate macht das ganze zu einem unverständlichen Datenkauderwelsch, der aber ggf. trotzdem interpretiert wird. Die ccconf-Abfrage ist dazu eine Art Test.

Dann: wenn Du zwei CUL nutzt, und das beides 868-er sind, haben die die gleiche USB-Kennung, was wieder zu Problemen führen kann. wenn die Ausgabe von ls -l /dev/serial/by-id bis auf den angezeigten link auf das ACM-Device identisch ist, solltest Du entweder eine firmware nochmal selber bauen (der USB-Name steht irgendwo im Quellcode,  dort wäre die ID zu ändern), oder beide dann "by-path" einbinden.

Ich würde - bei identischem by-id-Namen - also vorläufig erst mal einen abstöpseln und den anderen für FHEM löschen.

Gruß, Beta-User
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

walterschmitz

Hallo,

CCCconf hat bei mir ja was zurückgegeben. Und ich habe aktuell auch NUR den neuen dran. Und die Baudrate habe ich auch schon auf 38400 geändert.
Soweit erst mal das?

Trotzdem kam das :-(

Ich könnte zum Vergleich den zweiten (alten) CUL gerne mal zusätzlich aktivieren und schauen, ob es Unterschiede gibt... dann ist aber die Fehlersuche noch schwieriger, oder?

Das mit den beiden CUL und der gleichen ID versteh ich grad nicht. Ich habe ja nur einen drin.
Das was du meinst, wäre nur dann der Fall, wenn BEIDE gleichzeitig eingebaut wären, oder? Aktuell sind die ausgetauscht! und da verwundert mich das nicht, dass die by-id-Links gleich aussehen.
Ich würde eher davon ausgehen, dass wenn ich BEIDE drin hätte, ich 2 by-id-links erhalten würde... um sie irgendwie zu unterscheiden. Aber ausprobiert hab ich das noch nicht. Könnte ich aber gern, wenn das hilfreich wäre.

Eine Firmware selbst gebaut habe ich übrigens noch nicht. Ich habe die aktuelle von von culfw.de geholt und unter Windows via Flip 3.4.7 installiert (Installiert / geflashed habe ich die CUL-FW_1.67\culfw-1.67\Devices\CUL\CUL_V3.hex aus dem File 1.67). Da ich sowas noch nie gemacht habe, versteh ich natürlich auch nicht, was du meinst mit USB-Name steht irgendwo im Quelltext :-) Aber soweit sind wir ja auch noch nicht.


Beta-User

Sorry, ich wollte dich nicht verwirren.

Nur ein CUL angestöpselt ist gut, und am flashen scheint es auch nicht zu liegen, daher: an der Stelle
ist erst mal keine Aktion erforderlich.

Habe jetzt auch mal meinen CUL auf @38400 umgestellt, weil ich wissen wollte, ob da was zurückkommt. Ergebnis: ich bekomme bei beiden Datenraten eine Antwort auf get ccconf....
Soweit ich mich jetzt nach etwas Rätseln erinnere war es so, dass ein Modem (=ACM-Gerät) die Datenrate wohl auf Anforderung umstellen können muß. Damit dürfte also beides gehen...

ABER: Die Antwort auf get ccconf war eine andere: @38400 habe ich eine bwith von 325KHz zurückgemeldet erhalten, auf @9600 waren es erst nur etwas mehr als 100 (wie bei dir unten).

Setz mal bitte ein "raw e" ab, damit wird der CUL in den Werkszustand zurückgesetzt. Vielleicht war schlicht die Empfindlichkeit so verstellt, dass nicht mehr alle Geräte innerhalb des Frequenzbands lagen.

Ansonsten ist es wirklich irgendwas MAX-Spezifisches, da kann ich dann auch nicht weiterhelfen.

Das mit den Änderungen im Quellcode ist nur dann relevant, wenn beide CUL an derselben Maschine genutzt werden sollen, aber damit solltest du dich erst mal nicht belasten.

Gruß, Beta-User
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

walterschmitz

Hallo,

ich hab mal Set Raw e gemacht.
Danach warte ich mal ab. Und um die Uhrzeit zu markieren hab ich mal ein Shutdown restart gemacht... Dann hab ich es in der Log-File gleich leichter mit suchen :-P

So... die Meldung danach war:
2017.10.29 15:52:58 0: Server shutdown
2017.10.29 15:53:00 1: Including fhem.cfg
2017.10.29 15:53:00 3: telnetPort: port 7072 opened
2017.10.29 15:53:01 3: WEB: port 8083 opened
2017.10.29 15:53:01 3: WEBphone: port 8084 opened
2017.10.29 15:53:01 3: WEBtablet: port 8085 opened
2017.10.29 15:53:01 2: eventTypes: loaded 374 events from ./log/eventTypes.txt
2017.10.29 15:53:01 3: Opening CUL868 device /dev/serial/by-id/usb-busware.de_CUL868-if00
2017.10.29 15:53:01 3: Setting CUL868 serial parameters to 38400,8,N,1
2017.10.29 15:53:01 3: CUL868: Possible commands: ABbCeFGhiKkLlMmNRTtUuVWXxYZ
2017.10.29 15:53:01 3: CUL868 device opened
2017.10.29 15:53:01 2: Switched CUL868 rfmode to MAX
2017.10.29 15:53:01 3: CUL_MAX_Check: Detected firmware version 167 of the CUL-compatible IODev
2017.10.29 15:53:02 1: Including ./log/fhem.save
2017.10.29 15:53:02 1: usb create starting
2017.10.29 15:53:02 3: Probing CUL device /dev/ttyAMA0
2017.10.29 15:53:02 3: Probing TCM_ESP3 device /dev/ttyAMA0
2017.10.29 15:53:02 3: Probing ZWDongle device /dev/ttyAMA0
2017.10.29 15:53:03 3: Probing FRM device /dev/ttyAMA0
2017.10.29 15:53:08 1: usb create end
2017.10.29 15:53:08 2: SecurityCheck:  WEB,WEBphone,WEBtablet has no associated allowed device with basicAuth. telnetPort has no associated allowed device with password/globalpassword.  Restart FHEM for a new check if the problem is fixed, or set the global attribute motd to none to supress this message.
2017.10.29 15:53:08 0: Featurelevel: 5.8
2017.10.29 15:53:08 0: Server started with 40 defined entities (fhem.pl:15294/2017-10-20 perl:5.024001 os:linux user:fhem pid:26543)
2017.10.29 15:53:22 3: CUL868: Unknown code Z020208, help me!
2017.10.29 15:53:28 3: CUL868: Unknown code Z0118, help me!
2017.10.29 15:53:30 2: CUL_MAX_SendQueueHandler: Missing ack from 08d15f for 0f00040312345608d15f00111d0fb59b
2017.10.29 15:53:30 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 52, but we need 113. Waiting 61 seconds. Currently 2 messages are waiting to be sent.


Die beiden Unkown Codes werden jetzt angezeigt... und direkt ein Missing Ack sowie die beiden - eigentlich dürften sie ja gar nicht existieren - Messages, die gerade nicht verschickt werden konnte.

Aber warten wir mal ab und harren der Dinge, die gleich kommen.
Danke erst mal.

walterschmitz

Ich habe jetzt mal FHEM deinstalliert (apt-get remove und purge und autoremove) damit alles weg ist.

Und anschließend nach der FHEM-Wiki Seite wieder installiert über die Nightly-Debian-Variante.

Und auf eine ganz blanke FHEM-Installation mit Autocreate... alle Devices werden nach einiger Zeit wieder gefunden... kann ich IMMER NOCH nicht einen Befehl an ein Device absetzen.

Ich erhalte umgehend wieder die Meldung
2017.11.08 23:25:07 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 107, but we need 110. Waiting 3 seconds. Currently 1 messages are waiting to be sent.
2017.11.08 23:25:17 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 7, but we need 110. Waiting 103 seconds. Currently 1 messages are waiting to be sent.


Was ist denn hier für mich echt noch machbar...
Neuer CUL868 --> keine Änderung
Neues FHEM --> keine Änderung
keine Veränderungen am Quellcode irgendwelcher Files
keine Device verändert (funktioniert ohne FHEM problemlos zwischen den gepairten Devices)
keine handgebauten Devices oder CULs

Ich bin echt ratlos, was ich machen könnte, bzw. was hier gerade falsch läuft.

walterschmitz

#39
und ich schon wieder... mal beim CUL_MAX das verbose auf 5 gestellt...

jetzt erhalte ich so ne Meldung im Log:
CUL_MAX_Send: enqueuing 0b02004012345616d5430063
123456 ist die Def, die beim CUL_MAX durch den Autocreate eingetragen wurde
16d543 ist die ID des Device

der Rest drum rum, sagt mir noch nichts.
Ist auf jeden Fall das Device, welches ich einen Testbefehl gegeben habe.

Auf jeden Fall habe ich jetzt rausgefunden, was meine Credtis verbraucht (denke ich):
2017.11.09 00:44:33 5: CUL_MAX_BroadcastTime: payload 110900ace1
2017.11.09 00:44:33 5: Broadcast time to 0e1d4f
2017.11.09 00:44:33 5: CUL_MAX_Send: enqueuing 0f0404031234560e1d4f00110900ace1
2017.11.09 00:44:33 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:33 5: needPreamble: 1, necessaryCredit: 113, credit10ms: 143
2017.11.09 00:44:33 5: Updating TimeInformation payload
2017.11.09 00:44:34 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:34 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:35 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:35 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:36 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:36 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:36 5: CUL_MAX_SendQueueHandler: Retry 0e1d4f for 0f0404031234560e1d4f00110900ace1 count: 3
2017.11.09 00:44:39 5: CUL_MAX_SendQueueHandler: 1 items in queue
2017.11.09 00:44:39 5: needPreamble: 1, necessaryCredit: 113, credit10ms: 36
2017.11.09 00:44:39 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 36, but we need 113. Waiting 77 seconds. Currently 1 messages are waiting to be sent.

Das ist immer in regelmässigen / unregelmässigen Abständen das Broadcast time an bestimmte Devices. Und hierbei entsteht ein Versand, der nicht beantwortet wird bzw. der zu einem Fehler führt.
Bei einigen Devices führt das dazu, dass die Queue voller und voller wird.
Das sind alles meine Devices, die durch den AutoCreate erstellt wurden... an denen ich noch keine Veränderungen vorgenommen habe... also alles blankes FHEM (bis auf das Verbose 5 beim CULMAX)

aber das ist jetzt so tief im Quellcode / FHEM enthalten... da geh ich momentan nicht ohne Tipps von Cracks ran :-)

walterschmitz

so... nächste Vermutung, es sind wieder 365 Messages in der Pipeline :-(

Ich gehe davon aus, dass FHEM regulär arbeitet... dann in x-beliebigen Zeitabschnitten was an die Devices schicken möchte, und das nicht angenommen wird, weil die Verbindung zwischen Device und CUL nicht sauber ist.

WIE KANN ICH NACHTRÄGLICH Device, die mal mit dem CUL gepaired waren, wieder trennen und repairen bzw. ich würde dem CULMAX mal ein anderes DEF (nicht 123456 von der Autocreate vergeben) geben sondern dies abändern. Anschließend würde ich gerne jeden Tag zwei Device (WT und HT) zurücksetzen und repairen, die jeweils ohen FHEM pairen und anschließend in FHEM associaten.

Wie sollte ich hier vorgehen. ich gehe eher davon aus, dass ich jetzt die Geräte alle auf Werkseinstellung zurücksetzen müsste?

Andere Vorschläge?

Muss an den Devices mal später die Firmware upgegradet werden? Nur so als Idee? Wenn ja, wie macht man das via FHEM? Dann würde wirklich jede Firmware aktuell sein (CUL, DEVICEs und FHEM wird sowieso immer updated)

zweiundzwanzig

Hi,
ich kenne Probleme mit nicht richtig gepairten Devices. Bei mir trat das immer auf wenn ich zu ungeduldig war und wärend dem Pairen die credits alle wurden.
Ohne jetzt jedes Detail deiner Probleme nachvollzogen zu haben würde ich, wenn das Device schon in deiner Config mit ID vorhanden ist, vorschlagen:

1. autocreate abschalten

2. Sicherstellen, dass genug credits vorhanden sind (man braucht zum Pairen eine Menge davon weil die Wochenprogramme übertragen werden)

3. Device am Device selber resetten (Werkseinstellung) und dann einfach neu pairen. Dem CUL_MAX ist das komplett egal.

Vielleicht löst das die Probleme ja schon?
2x MAX CuBe mit a-culf im Moritzbetrieb
1x MAX CuBe mit a-culf im Homematicbetrieb
60x MAX Heizkörperthermostat plus | 2x HM Schaltaktoren | 1x MAX Wandthermostat
1x FHEM Ubuntu Server auf VMWare
24 Räume, die durch ical Kalender geheizt werden

walterschmitz

so.... ganz langsam und mit Bedacht nehm ich jeden Tag ein WT vom Netz und resette es. Dann repaire ich es mit dem CUL und FHEM.
Später mach ich die HT und FK fertig... und dann werde ich Tag für Tag immer wieder ein Gerät mit den jeweils anderen pairen, damit alles funktioniert, wenn bei FHEM mal wieder (hoffentlich nie) so ein Crash bzw. Ausfall passiert.

Um das aber zeitnah zu benachrichtigen würde ich mir wünschen, dass ich über diese Not Enough Credits-Meldungen ein Notify erstellen könnte.

Ich habe aktuell aus dem EventMonitor raus KEINE Möglichkeit daraus ein Event zu machen.
Kann mir jemand erklären, wie ich das hinbekommen könnte bzw. würde jemand eine FHEM Erweiterung programmieren, die bei Credits-Problemen eine Benachrichtigung rausschickt (per Email oder Pushbenachrichtigung).

Dann hätte ich damals umgehend reagieren können... so ist es erst nach langem Abwarten aufgefallen, wo das Problem lag.


zweiundzwanzig

Mailversand geht so: https://wiki.fhem.de/wiki/E-Mail_senden#Raspberry_Pi

Mein Notify dafür sah ungefähr so aus allerdings passiert das bei 900 credits zu oft! :

defmod N_credits_Email notify .*CUBe_.*:credit10ms:.* { if (($EVTPART1 < 100)&& (time gt $main::NewMailtimeCredits)) {# Variable NewMailtime ist in 99_myutils definiert!\
  { SendeMail('bla@googlemail.com', 'FHEM Credits Warnung!', $NAME.': '.$EVENT)};; \
   Log 3, "$NAME : CUBE-Warnung $EVTPART1";; \
   $main::NewMailtimeCredits = time + 14400;; #4 Stunden bis zur nächsten Mail\
  } \
}
attr N_credits_Email room CUN,Hausmeister
2x MAX CuBe mit a-culf im Moritzbetrieb
1x MAX CuBe mit a-culf im Homematicbetrieb
60x MAX Heizkörperthermostat plus | 2x HM Schaltaktoren | 1x MAX Wandthermostat
1x FHEM Ubuntu Server auf VMWare
24 Räume, die durch ical Kalender geheizt werden

walterschmitz

würde das auch ohne CUBE funktionieren und nur mit einem CUL?

Dann müsste doch der reguläre Ausdruck ein anderer sein, oder?

Ansonsten müssten / könnte der Rest fast gleich bleiben?
Danke für die Vorlage des EmailNotify.