Test Adapter BMW/Mini v2.0.0

[lessthanmore]

@lobomau said in Test Adapter BMW/Mini v2.0.0:

soviel muss BMW ja gar nicht geändert haben. "Rate limit is exceeded" klingt ja danach, dass das Limit an Datenabfragen gesenkt worden ist. Eventuell zieht der Adapter auch zu viele Daten. Aber dazu kann ich gar nichts sagen, da ich von Adapterentwicklung keine Ahnung habe.

Wie gesagt, alle 10 Minuten. Läuft in der owb aber nicht im Adapter. Auch nach 24 Stunden Pause kommt die Meldung.
Mir ist bewusst was die Meldung sagt. Deswegen vermute ich dass evtl. im Adapter trotz anderer Einstellung zu häufig abgefragt wird.

[Marc Berg]

Ich habe mal die Version von Github geladen und den Start mitprotokolliert. Vielleicht hilft es ja.

2023-12-05 08:11:21.503 - debug: bmw.0 (61656) Redis Objects: Use Redis connection: redis:6379
2023-12-05 08:11:21.514 - debug: bmw.0 (61656) Objects client ready ... initialize now
2023-12-05 08:11:21.515 - debug: bmw.0 (61656) Objects create System PubSub Client
2023-12-05 08:11:21.515 - debug: bmw.0 (61656) Objects create User PubSub Client
2023-12-05 08:11:21.534 - debug: bmw.0 (61656) Objects client initialize lua scripts
2023-12-05 08:11:21.536 - debug: bmw.0 (61656) Objects connected to redis: redis:6379
2023-12-05 08:11:21.540 - debug: bmw.0 (61656) Redis States: Use Redis connection: redis:6379
2023-12-05 08:11:21.542 - debug: bmw.0 (61656) States create System PubSub Client
2023-12-05 08:11:21.543 - debug: bmw.0 (61656) States create User PubSub Client
2023-12-05 08:11:21.546 - debug: bmw.0 (61656) States connected to redis: redis:6379
2023-12-05 08:11:21.556 - debug: bmw.0 (61656) Plugin sentry Do not initialize Plugin (enabled=false)
2023-12-05 08:11:21.558 - debug: bmw.0 (61656) Plugin sentry destroyed because not initialized correctly
2023-12-05 08:11:21.585 - info: bmw.0 (61656) starting. Version 2.7.0 (non-npm: TA2k/ioBroker.bmw) in /opt/iobroker/node_modules/iobroker.bmw, node: v18.18.2, js-controller: 5.0.17
2023-12-05 08:11:21.897 - debug: bmw.0 (61656) {"redirect_to":"redirect_uri=com.bmw.connected://oauth?client_id=<private>&response_type=code&scope=openid profile email offline_access smacc vehicle_data perseus dlm svds cesim vsapi remote_services fupo authenticate_user&state=<private>&authorization=<private>*"}
2023-12-05 08:11:22.157 - debug: bmw.0 (61656) "com.bmw.connected://oauth?code=<private>&nonce=login_nonce"
2023-12-05 08:11:22.158 - debug: bmw.0 (61656) <private>
2023-12-05 08:11:22.355 - debug: bmw.0 (61656) {"gcid":"<private>","token_type":"Bearer","access_token":"<private>","refresh_token":"<private>","scope":"smacc vehicle_data perseus dlm svds openid profile vsapi remote_services authenticate_user cesim offline_access email fupo","expires_in":3599,"id_token":"<private>"}
2023-12-05 08:11:22.356 - info: bmw.0 (61656) Start getting mini vehicles
2023-12-05 08:11:22.356 - debug: bmw.0 (61656) getVehiclesv2
2023-12-05 08:11:22.781 - debug: bmw.0 (61656) [{"vin":"<private>","mappingInfo":{"isAssociated":null,"isLmmEnabled":false,"mappingStatus":"CONFIRMED","isPrimaryUser":true},"appVehicleType":"CONNECTED","attributes":{"lastFetched":"2023-12-05T07:11:22.498Z","model":"Cooper SE","year":2023,"color":4290295992,"brand":"MINI","driveTrain":"ELECTRIC","headUnitType":"ENTRY_EVO","headUnitRaw":"ENAVEVO","hmiVersion":"ID5","softwareVersionCurrent":{"puStep":{"month":3,"year":23},"iStep":530,"seriesCluster":"F056"},"softwareVersionExFactory":{"puStep":{"month":3,"year":23},"iStep":530,"seriesCluster":"F056"},"telematicsUnit":"ATM1","bodyType":"F56","countryOfOrigin":"DE","driverGuideInfo":{"androidAppScheme":"com.mini.driversguide.row","iosAppScheme":"minidriversguide:///open","androidStoreUrl":"https://play.google.com/store/apps/details?id=com.mini.driversguide.row","iosStoreUrl":"https://apps.apple.com/de/app/id834510424?mt=8"}}}]
2023-12-05 08:11:22.781 - info: bmw.0 (61656) Found 1 mini vehicles
2023-12-05 08:11:42.795 - debug: bmw.0 (61656) update <private>.chargingSessions.
2023-12-05 08:11:44.049 - debug: bmw.0 (61656) {"paginationInfo":{},"chargingSessions":{"total":"~ 39 kWh","numberOfSessions":"2","chargingListState":"HAS_SESSIONS","sessions":[{"id":"2023-12-02T09:28:14Z_281c8cbb","title":"Samstag 10:28","subtitle":"<private> • 11h 51min • ~ 4,70 EUR","energyCharged":"~ 19 kWh","sessionStatus":"FINISHED","isPublic":false},{"id":"2023-12-01T18:16:07Z_281c8cbb","title":"Freitag 19:16","subtitle":"<private> • 12h 19min • ~ 5 EUR","energyCharged":"~ 20 kWh","sessionStatus":"FINISHED","isPublic":false}],"costsGroupedByCurrency":["~ 9,70 EUR"]},"datePicker":{"startDate":"2023-10-23T09:12:45Z","selectedDate":"2023-12-02T09:28:14Z","endDate":"2023-12-05T07:11:44Z"}}
2023-12-05 08:11:44.093 - warn: bmw.0 (61656) Used invalid characters: bmw.0.<private>.chargingSessions.2023-12.costsGroupedByCurrency.~ 9,70 EUR changed to bmw.0.<private>.chargingSessions.2023-12.costsGroupedByCurrency.~ 9_70 EUR
2023-12-05 08:11:44.095 - warn: bmw.0 (61656) State "bmw.0.<private>.chargingSessions.2023-12.costsGroupedByCurrency.~ 9,70 EUR" has no existing object, this might lead to an error in future versions
2023-12-05 08:11:54.123 - debug: bmw.0 (61656) update <private>.charging-statistics.
2023-12-05 08:11:54.358 - debug: bmw.0 (61656) {"description":"Dezember 2023","optStateType":"OPT_IN_WITH_SESSIONS","statistics":{"totalEnergyCharged":39,"totalEnergyChargedSemantics":"Insgesamt circa 39 Kilowattstunden geladen","symbol":"~","numberOfChargingSessions":2,"numberOfChargingSessionsSemantics":"2 Ladevorgänge"}}
2023-12-05 08:11:59.380 - debug: bmw.0 (61656) update <private>
2023-12-05 08:11:59.481 - info: bmw.0 (61656) Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
2023-12-05 08:12:04.482 - debug: bmw.0 (61656) update <private>
2023-12-05 08:12:04.567 - info: bmw.0 (61656) Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
2023-12-05 08:12:09.570 - debug: bmw.0 (61656) update <private>
2023-12-05 08:12:09.681 - info: bmw.0 (61656) Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
2023-12-05 08:12:14.681 - debug: bmw.0 (61656) update <private>
2023-12-05 08:12:15.834 - debug: bmw.0 (61656) {"state":{"isLeftSteering":true,"lastFetched":"2023-12-05T07:12:14.776Z","lastUpdatedAt":"2023-12-04T15:21:11Z","isLscSupported":true,"range":144,"doorsState":{"combinedSecurityState":"SECURED","leftFront":"CLOSED","rightFront":"CLOSED","combinedState":"CLOSED","hood":"CLOSED","trunk":"CLOSED"},"windowsState":{"leftFront":"CLOSED","rightFront":"CLOSED","combinedState":"CLOSED"},"location":{"coordinates":{"latitude":<private>.08157944444444,"longitude":<private>.635013055555556},"address":{"formatted":"<private>"},"heading":316},"currentMileage":1132,"requiredServices":[],"checkControlMessages":[],"chargingProfile":{"chargingControlType":"WEEKLY_PLANNER","reductionOfChargeCurrent":{"start":{"hour":0,"minute":0},"end":{"hour":0,"minute":0}},"chargingMode":"IMMEDIATE_CHARGING","chargingPreference":"CHARGING_WINDOW","departureTimes":[{"id":1,"action":"DEACTIVATE","timerWeekDays":[]},{"id":2,"action":"DEACTIVATE","timerWeekDays":[]},{"id":3,"action":"DEACTIVATE","timerWeekDays":[]},{"id":4,"action":"DEACTIVATE","timerWeekDays":[]}],"climatisationOn":false,"chargingSettings":{"targetSoc":100,"idcc":"NO_ACTION","hospitality":"NO_ACTION"}},"electricChargingState":{"chargingLevelPercent":91,"range":144,"isChargerConnected":false,"chargingStatus":"INVALID","chargingTarget":100},"combustionFuelLevel":{"range":144},"driverPreferences":{"lscPrivacyMode":"OFF"},"climateTimers":[{"isWeeklyTimer":false,"timerAction":"DEACTIVATE","timerWeekDays":[],"departureTime":{"hour":7,"minute":0}},{"isWeeklyTimer":true,"timerAction":"DEACTIVATE","timerWeekDays":["MONDAY"],"departureTime":{"hour":7,"minute":0}},{"isWeeklyTimer":true,"timerAction":"DEACTIVATE","timerWeekDays":["MONDAY"],"departureTime":{"hour":7,"minute":0}}],"securityOverviewMode":null},"capabilities":{"a4aType":"USB_ONLY","climateNow":true,"climateFunction":"AIR_CONDITIONING","horn":true,"isBmwChargingSupported":false,"isCarSharingSupported":false,"isChargeNowForBusinessSupported":true,"isChargingHistorySupported":true,"isChargingHospitalityEnabled":false,"isChargingLoudnessEnabled":false,"isChargingPlanSupported":true,"isChargingPowerLimitEnabled":false,"isChargingSettingsEnabled":false,"isChargingTargetSocEnabled":false,"isCustomerEsimSupported":false,"isDataPrivacyEnabled":false,"isDCSContractManagementSupported":true,"isEasyChargeEnabled":false,"isMiniChargingSupported":true,"isEvGoChargingSupported":true,"isRemoteHistoryDeletionSupported":false,"isRemoteEngineStartSupported":false,"isRemoteServicesActivationRequired":false,"isRemoteServicesBookingRequired":false,"isScanAndChargeSupported":true,"lastStateCallState":"ACTIVATED","lights":true,"lock":true,"sendPoi":true,"unlock":true,"vehicleFinder":true,"vehicleStateSource":"LAST_STATE_CALL","isRemoteHistorySupported":true,"isWifiHotspotServiceSupported":false,"isNonLscFeatureEnabled":false,"isSustainabilitySupported":false,"isSustainabilityAccumulatedViewEnabled":false,"specialThemeSupport":[],"isRemoteParkingSupported":false,"remoteChargingCommands":{},"isClimateTimerWeeklyActive":false,"digitalKey":{"state":"NOT_AVAILABLE","bookedServicePackage":"NONE","vehicleSoftwareUpgradeRequired":false,"isDigitalKeyFirstSupported":false},"isPersonalPictureUploadSupported":false,"isPlugAndChargeSupported":false,"isOptimizedChargingSupported":false}}
2023-12-05 08:12:15.834 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>
2023-12-05 08:12:25.835 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>
2023-12-05 08:12:35.837 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>
2023-12-05 08:12:45.838 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>

Dann kam noch was Interessantes (Quota) hinterher:

2023-12-05 08:52:57.841 - debug: bmw.0 (61656) update <private>
2023-12-05 08:52:59.167 - info: bmw.0 (61656) Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
2023-12-05 08:53:04.169 - debug: bmw.0 (61656) update <private>
2023-12-05 08:53:04.254 - info: bmw.0 (61656) Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
2023-12-05 08:53:09.255 - debug: bmw.0 (61656) update <private>
2023-12-05 08:53:09.364 - warn: bmw.0 (61656) Out of call volume quota. Quota will be replenished in 00:06:51.
2023-12-05 08:53:09.364 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>
2023-12-05 08:53:19.365 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>
2023-12-05 08:53:29.365 - debug: bmw.0 (61656) updateChargingSessionv2 to early <private>

[bahnuhr]

@marc-berg
Ja, das mit dem Quota hatte ich heute auch.

[McLane]

Gerade gesehen, es gibt auf Git schon seit 10 Stunden die Version 2.7.0.
Bei mir ist noch 2.6.3 installiert und habe gerade gesehen, dass seit Gestern Nachmittag kein Rate limit Error aufgetreten ist. Lasse das jetzt erst mal so laufen.

[manny4566]

@lobomau

Hab gerade die 2.7.0 installiert und kurz danach auch wieder evcc gestartet.

5 minuten lief es bis die API wieder dicht gemacht hat,

Jetzt kommt wieder diese Meldungen, dass das Rate limit erreicht ist.
Das liegt an der Api, dass diese zu macht.

Also entweder bekommt man BMW dazu ihre Rate zu erhöhen oder man muss die Adapter und was noch so alles auf die BMW Api zugreift (z.b. evcc) sparsamer machen, was die Requests angeht.
Ich weiß jetzt nicht wie der Adapter programmiert ist. Ob er nur einen Request macht oder mehrere. Da aber die Rate von scheinbar 100/min geknackt wird, scheint da irgendwo das Problem zu sein.

bmw.0
	2023-12-05 11:21:31.616	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:21:26.541	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:17:43.364	warn	Out of call volume quota. Quota will be replenished in 00:42:17.
bmw.0
	2023-12-05 11:17:38.278	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:17:22.604	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:16:52.008	warn	Out of call volume quota. Quota will be replenished in 00:43:09.
bmw.0
	2023-12-05 11:16:46.953	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:16:41.866	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds
bmw.0
	2023-12-05 11:16:26.011	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds

[bahnuhr]

Bei mir auch.
Meldung kam sofort nach dem restart:

bmw.0
2023-12-05 11:31:59.185	error	{"statusCode":429,"message":"Rate limit is exceeded. Try again in 1 seconds."}

bmw.0
2023-12-05 11:31:59.185	error	AxiosError: Request failed with status code 429

bmw.0
2023-12-05 11:31:59.185	error	getvehicles v2 failed

bmw.0
2023-12-05 11:31:59.051	info	Start getting bmw vehicles

bmw.0
2023-12-05 11:31:58.412	info	starting. Version 2.7.0 (non-npm: TA2k/ioBroker.bmw) in /opt/iobroker/node_modules/iobroker.bmw, node: v18.18.2, js-controller: 5.0.16

[tops4u]

Bei mir kommt die Fehlermeldung auch schon seit einiger Zeit. Update heute gemacht.

Log vom Start:

starting. Version 2.7.0 (non-npm: TA2k/ioBroker.bmw) in /opt/iobroker/node_modules/iobroker.bmw, node: v18.18.2, js-controller: 5.0.12

Leider kommt die Fehlermeldung erneut. Was mir auffällt, dass sie v.a. am Tag kommt, während der Nacht habe ich fast keine solche Meldungen. Da frage ich mich eher ob BMW ihr API resp. Infrastruktur im Griff hat?

[tombox]

@tops4u Rate limit is exceeded habe ich jetzt als info. damit man nachvollziehen kann ob der 5sek retry funktioniert wenn ja könnte man es ausblenden.
Für mich ist noch nicht ganz ersichtlich warum es 5s später funktioniert

[McLane]

Also mein Log ist nach wie vor sauber (Intervall=10min). Dabei habe ich gerade einige Kilometer mit meinem F31 zurückgelegt. Und mir fiel dabei ein, dass ich stets nebenbei die App AAIDrive laufen habe, welche ebenfalls über die API zugreift.
Wenn man die Posts hier liest, kann man eigentlich von der Logik her ausschliessen, dass BMW die Zugriffe beschränkt.
Denke die haben zur Zeit tatsächlich Probleme mit der Infrastruktur oder den Ressourcen allgemein.

[lobomau]

@tombox als eben nach 2 Std. keine Werte geupdatet wurden, habe ich den Adapter neugestartet. Da hat er wohl drei Versuche unternommen bis es geklappt hat. Werte wurde nun geholt. Ja, komisch warum es dann plötzlich doch geht.

bmw.0
2023-12-05 13:31:22.866	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds

bmw.0
2023-12-05 13:31:17.816	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds

bmw.0
2023-12-05 13:31:12.763	info	Rate limit is exceeded. Try again in 1 seconds. Retry in 5 seconds

Edit.: log zeigt sich seit einigen Stunden unauffällig. Auto wird geladen und Akku % aktualisiert.

[vowill]

@tombox
Super, habe den 2.7.0 seit heute, 17:00 Uhr, im Einsatz, und keine Fehlermeldung. Intervall nach wie vor auf 15min.
VIELEN DANK!
Einziges noch offenes Thema sind die fehlenden Datenpunkte für den Servicebedarf.

[bahnuhr]

@tombox

Instanz neu starten, dann ist der Fehler wieder da.

bmw.0
2023-12-06 08:20:52.126	error	{"statusCode":429,"message":"Rate limit is exceeded. Try again in 1 seconds."}

bmw.0
2023-12-06 08:20:52.126	error	AxiosError: Request failed with status code 429

bmw.0
2023-12-06 08:20:52.125	error	getvehicles v2 failed

bin aktuell auf git 2.7.0.
und Intervall 15 Minuten.

[McLane]

@bahnuhr
Merkwürdig, bei mir funktioniert alles normal, Daten werden zufriedenstellend aktualisiert. Wie viele Lücken es gibt, versuche ich mal zu protokollieren.
Was mir in der MyBMW App auffiel und was auf generelle Probleme schließen lässt, ist, dass man mehrmals auf "Status prüfen" klicken muss, bis der Status dann tatsächlich angezeigt wird. Meldung: Sie sind offline!

Edit: Habe mal bissel Protokoll geführt. Sieht recht gut aus, kleine Aussetzer sind kein Problem.
Intervall immer noch 10 min. Version: 2.7.2

[manny4566]

@mclane

Ja, die Aktualisierung der Daten funktioniert an sich. Trotz der Meldungen, die hin und wieder auftreten und der API Zickerei. Daten kommen aber weiterhin an.

[mike1429]

@marc-berg
Hallo. Hat jemand das Problem mit "costsGroupedByCurrency" (siehe Marc Berg 15 Nov 2023, 11:30) gelöst? Bekomme es immer wieder, und zwar seit der letzten Adapter Aktualisierung.
Danke!

[tombox]

@mike1429 ein debug log via mail wäre hilfreich
tombox2020@gmail.com

[mike1429]

@tombox
Gerne. Hier z.B.:

2023-12-28 11:04:35.136 - warn: host.buanet-iobroker1-Server States 127.0.0.1:47846 Error from InMemDB: Error: The pattern "bmw.0.xxxxxxxxx.chargingSessions.2023-11.costsGroupedByCurrency.~ 24,78 EUR" is not a valid ID pattern
at Object.pattern2RegEx (/opt/iobroker/node_modules/@iobroker/js-controller-common/src/lib/common/tools.ts:2470:15)
at StatesInMemoryServer.handleSubscribe (/opt/iobroker/node_modules/@iobroker/db-base/src/lib/inMemFileDB.ts:324:59)
at StatesInMemoryServer._subscribeForClient (/opt/iobroker/node_modules/@iobroker/db-states-file/src/lib/states/statesInMemFileDB.js:258:14)
at RedisHandler. (/opt/iobroker/node_modules/@iobroker/db-states-jsonl/src/lib/states/statesInMemServerRedis.js:395:26)
at RedisHandler.emit (node:events:513:28)
at RedisHandler.emit (node:domain:489:12)
at Immediate._onImmediate (/opt/iobroker/node_modules/@iobroker/db-base/src/lib/redisHandler.ts:209:37)
at processImmediate (node:internal/timers:466:21)

2023-12-28 11:04:35.141 - error: admin.0 (26310) Cannot subscribe "bmw.0.xxxxxxxxx.chargingSessions.2023-11.costsGroupedByCurrency.~ 24,78 EUR": Error The pattern "bmw.0.xxxxxxxxx.chargingSessions.2023-11.costsGroupedByCurrency.~ 24,78 EUR" is not a valid ID pattern

Es kam auch mal die Meldung, dass "," durch "_" ersetzt wird, also aus 24,78 wurde dann 24_78

Danke!

[tombox]

@mike1429 ich brauch eine debug log via mail

[mike1429]

@tombox
Sorry, sollte per mail raus... Reicht das so?

[mike1429]

@tombox
Ist gerade raus