[Ovmsdev] Polling keeps car awake (VW e-Up at least)

Mon Aug 3 12:19:34 HKT 2020

Mornin,

Source is here: 
https://github.com/devmarxx/Open-Vehicle-Monitoring-System-3/tree/master/vehicle/OVMS.V3/components/vehicle_vweup/src

Attached are two logs. I haven't had the can-monitor active unfortuantely..

*VWUP_OFF_TICKER_THRESHOLD 5 with 4 trys.log*
As the name says it polls every 5 seconds in PollState=1 and swaps back 
to PollState=0 after 5*4=20 seconds.
Until line 35 you see the CAN errors as the vehicle is OFF. Then I 
unlocked the car and in line 38 I get the first reply.
Around line 90 I locked the car again. It polls, but gets no reply, _but 
not error either_ (?!).
Line 118 sets the PollState=0 and suddenly a response comes in. So in 
Line 123 I set the PollState=1 again.
The the game starts again: Polls get send, no reply but no error either. 
After 21 CarOffTickers I switch to PollState=0 and suddenly a reply 
comes in...

*VWUP_OFF_TICKER_THRESHOLD 10 with 4 trys.log
*Here I unlocked at line 57 and locked around line 100. After that polls 
get send, no reply, _but errors happen_. And the car is finally off.
Although I've tried the same thing later that day and the car didn't 
even go to sleep with Threshold=30!?!? So the behavior is not 100% 
reproducible (yet)...

@gateway throttling: In VCDS (which - hopefully - does only polling too) 
I have a little number showing me the refresh rates of the values. It 
indicates ~8 refreshes per second. So with 1 second shouldn't be any 
throttling.

@OBD "tester": I have no clue what this is ;) So if the polling 
framework doesn't do it, I don't do it. All I do is in the obd_eup.* files.

Soko

On 02.08.2020 20:12, Michael Balzer wrote:
> Soko,
>
> polling may keep the car awake, that's also an issue on the Kia e-Niro 
> IIRC.
>
> Changing the PollState can only affect the car indirectly via the 
> changed polls. Maybe you could add your code & a log?
>
> Regarding the poll replies stopping, is that also reflected in a CAN 
> log? Maybe the OBD gateway throttles if it sees too many requests? 
> (Hopefully not…)
>
> If the gateway does throttling: do you login to the OBD as a "tester" 
> and keep the session active by periodically sending the "tester 
> present" frame?
>
> Regards,
> Michael
>
>
> Am 02.08.20 um 19:30 schrieb Soko:
>>
>> Heya again,
>>
>> I'm trying to develop a detection for when the car is off/locked but 
>> I'm encountering a weird phenomena:
>>
>>   * Car is shut down and locked
>>   * OVMS connected
>>   * CAN poll for voltage (only one poll value active) with 30 secs
>>     fails with error (so far nothing weird)
>>   * Unlock the car via car-key remote
>>   * Poll succeeds and I'm switching from PollState=0 to PollState=1
>>     where I poll every 2 secs
>>   * Lock the car via car-key remote
>>   * _After 1 hour the polls still work and the car is active_
>>
>> Is something like this known from other vehicles? So basically my car 
>> never shuts down :(
>>
>> Another secondary weird thing:
>> When increasing the time to 5 secs for PollState=1 the polls get no 
>> reply and after 20 secs I swap back to PollState=0.
>> BUT the second the PollState changes the car replies again...
>> Even more weirdness: When PollState=1 time is 10 secs and I swap back 
>> to Pollstate=0 after 40 secs the same thing happens! Immediately I 
>> swap to PollState=0 the car replies again.
>> As if the PollState switching somehow wakes the car up??!
>>
>> Any ideas?
>>
>> Soko
>>
>>
>> _______________________________________________
>> OvmsDev mailing list
>> OvmsDev at lists.openvehicles.com
>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
>
> -- 
> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
>
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.openvehicles.com
> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20200803/e92e9be7/attachment.htm>
-------------- next part --------------
VWUP_OFF_TICKER_THRESHOLD 10 with 4 trys

I (15819) simcom: State timeout, transition to 13
I (15819) simcom: State: Enter PoweredOff state
I (15819) gsm-mux: Stop MUX
I (17189) webserver: HTTP POST /api/execute
I (17209) webcommand: HttpCommandStream[0x3f845444]: 3986256 bytes free, executing: log level verbose
OVMS# log level verbose
Logging level for * set to verbose
D (32819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (32819) can: can1: intr=4 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=23 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=8 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=55 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=9 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=63 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=10 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=71 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=12 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=87 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=13 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=95 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=14 rxpkt=0 txpkt=1 errflags=0x8440d9 rxerr=0 txerr=103 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=16 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=119 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=17 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=127 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=19 rxpkt=0 txpkt=1 errflags=0x204000 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=21 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
D (38799) websocket: new WebSocket slot 2, registered modifier is 3, reader 4
V (38799) websocket: WebSocketHandler[0x3f84a1d4] init: handler=0x3f84aa20 modifier=3
D (38799) websocket: WebSocket[0x3f84a1d4] handler 0x3f84aa20 opened; 3 clients active
D (38809) events: Signal(server.web.socket.opened)
I (39819) webserver: HTTP GET /
D (39889) websocket: WebSocket[0x3f84a1d4] handler 0x3f84aa20 closed; 2 clients active
D (39899) events: Signal(server.web.socket.closed)
I (39949) webserver: HTTP GET /edit
I (40009) webserver: HTTP POST /api/execute
I (40019) webcommand: HttpCommandStream[0x3f845b84]: 3972800 bytes free, executing: vfs ls '/store'
V (41769) websocket: WebSocketHandler[0x3f847b08] init: handler=0x3f84a558 modifier=3
D (41769) websocket: WebSocket[0x3f847b08] handler 0x3f84a558 opened; 3 clients active
D (41769) events: Signal(server.web.socket.opened)
D (60839) script: Duktape: Compacting DukTape memory
D (63819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (63819) can: can1: intr=115524 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=1 wdgreset=0 errreset=0
D (94819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (94819) can: can1: intr=231192 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=2 wdgreset=0 errreset=0
D (120839) script: Duktape: Compacting DukTape memory
D (125819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (125819) can: can1: intr=346826 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=3 wdgreset=0 errreset=0
D (156819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (156819) can: can1: intr=462494 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=4 wdgreset=0 errreset=0
D (180839) script: Duktape: Compacting DukTape memory
D (187819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (187819) can: can1: intr=578160 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=5 wdgreset=0 errreset=0
D (218819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (218819) can: can1: intr=693829 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=6 wdgreset=0 errreset=0
D (240829) script: Duktape: Compacting DukTape memory
D (249819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (249819) can: can1: intr=809485 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=7 wdgreset=0 errreset=0
D (280819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (280819) can: can1: intr=925149 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=135 rxovr=0 txovr=0 txdelay=8 wdgreset=0 errreset=0
E (287999) can: can1: intr=951929 rxpkt=0 txpkt=9 errflags=0x204c00 rxerr=0 txerr=127 rxovr=0 txovr=0 txdelay=8 wdgreset=0 errreset=0
D (300829) script: Duktape: Compacting DukTape memory
I (300889) housekeeping: 2020-08-02 17:13:30 CEST (RAM: 8b=94824-96380 32b=9576)
D (311819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
I (311829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (311829) vehicle: Receive Poll Response for 34/1e3b
D (311829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
I (311829) vwup.obd: Setting car state to ON
V (311829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
D (312819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (312819) vwup.obd: CarOffTicker increased to 1
I (312829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (312829) vehicle: Receive Poll Response for 34/1e3b
D (312829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (312829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (313819) vwup.obd: CarOffTicker increased to 1
V (314819) vwup.obd: CarOffTicker increased to 2
V (315819) vwup.obd: CarOffTicker increased to 3
V (316819) vwup.obd: CarOffTicker increased to 4
V (317819) vwup.obd: CarOffTicker increased to 5
V (318819) vwup.obd: CarOffTicker increased to 6
V (319819) vwup.obd: CarOffTicker increased to 7
V (320819) vwup.obd: CarOffTicker increased to 8
V (321819) vwup.obd: CarOffTicker increased to 9
V (322819) vwup.obd: CarOffTicker increased to 10
D (323819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (323819) vwup.obd: CarOffTicker increased to 11
I (323829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (323829) vehicle: Receive Poll Response for 34/1e3b
D (323829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (323829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (324819) vwup.obd: CarOffTicker increased to 1
V (325819) vwup.obd: CarOffTicker increased to 2
V (326819) vwup.obd: CarOffTicker increased to 3
V (327819) vwup.obd: CarOffTicker increased to 4
V (328819) vwup.obd: CarOffTicker increased to 5
V (329819) vwup.obd: CarOffTicker increased to 6
V (330819) vwup.obd: CarOffTicker increased to 7
V (331819) vwup.obd: CarOffTicker increased to 8
V (332819) vwup.obd: CarOffTicker increased to 9
V (333819) vwup.obd: CarOffTicker increased to 10
D (334819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (334819) vwup.obd: CarOffTicker increased to 11
I (334829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (334829) vehicle: Receive Poll Response for 34/1e3b
D (334829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (334829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (335819) vwup.obd: CarOffTicker increased to 1
V (336819) vwup.obd: CarOffTicker increased to 2
V (337819) vwup.obd: CarOffTicker increased to 3
V (338819) vwup.obd: CarOffTicker increased to 4
V (339819) vwup.obd: CarOffTicker increased to 5
V (340819) vwup.obd: CarOffTicker increased to 6
V (341819) vwup.obd: CarOffTicker increased to 7
V (342819) vwup.obd: CarOffTicker increased to 8
V (343819) vwup.obd: CarOffTicker increased to 9
V (344819) vwup.obd: CarOffTicker increased to 10
D (345819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (345819) vwup.obd: CarOffTicker increased to 11
V (346819) vwup.obd: CarOffTicker increased to 12
V (347819) vwup.obd: CarOffTicker increased to 13
V (348819) vwup.obd: CarOffTicker increased to 14
V (349819) vwup.obd: CarOffTicker increased to 15
V (350819) vwup.obd: CarOffTicker increased to 16
V (351819) vwup.obd: CarOffTicker increased to 17
V (352819) vwup.obd: CarOffTicker increased to 18
V (353819) vwup.obd: CarOffTicker increased to 19
V (354819) vwup.obd: CarOffTicker increased to 20
V (355819) vwup.obd: CarOffTicker increased to 21
D (356819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (356819) vwup.obd: CarOffTicker increased to 22
E (356819) can: can1: intr=951941 rxpkt=4 txpkt=15 errflags=0x204000 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=8 wdgreset=0 errreset=0
E (356819) can: can1: intr=951945 rxpkt=4 txpkt=15 errflags=0x8040d9 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=8 wdgreset=0 errreset=0
V (357819) vwup.obd: CarOffTicker increased to 23
V (358819) vwup.obd: CarOffTicker increased to 24
V (359819) vwup.obd: CarOffTicker increased to 25
V (360819) vwup.obd: CarOffTicker increased to 26
D (360839) script: Duktape: Compacting DukTape memory
V (361819) vwup.obd: CarOffTicker increased to 27
V (362819) vwup.obd: CarOffTicker increased to 28
V (363819) vwup.obd: CarOffTicker increased to 29
V (364819) vwup.obd: CarOffTicker increased to 30
V (365819) vwup.obd: CarOffTicker increased to 31
V (366819) vwup.obd: CarOffTicker increased to 32
D (367819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (367819) vwup.obd: CarOffTicker increased to 33
E (367819) can: can1: intr=992978 rxpkt=4 txpkt=15 errflags=0x8040d9 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=9 wdgreset=0 errreset=0
V (368819) vwup.obd: CarOffTicker increased to 34
V (369819) vwup.obd: CarOffTicker increased to 35
V (370819) vwup.obd: CarOffTicker increased to 36
V (371819) vwup.obd: CarOffTicker increased to 37
V (372819) vwup.obd: CarOffTicker increased to 38
V (373819) vwup.obd: CarOffTicker increased to 39
V (374819) vwup.obd: CarOffTicker increased to 40
V (375819) vwup.obd: CarOffTicker increased to 41
I (376819) vwup.obd: Setting car state to OFF
D (377819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (377819) can: can1: intr=1030293 rxpkt=4 txpkt=15 errflags=0x8040d9 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=10 wdgreset=0 errreset=0
D (408819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (408819) can: can1: intr=1145955 rxpkt=4 txpkt=15 errflags=0x8040d9 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=11 wdgreset=0 errreset=0
D (420829) script: Duktape: Compacting DukTape memory
D (439819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (439819) can: can1: intr=1261609 rxpkt=4 txpkt=15 errflags=0x8040d9 rxerr=0 txerr=129 rxovr=0 txovr=0 txdelay=12 wdgreset=0 errreset=0
-------------- next part --------------
VWUP_OFF_TICKER_THRESHOLD 5 with 4 trys

OVMS# log level verbose
Logging level for * set to verbose
D (32819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (32819) can: can1: intr=2 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=8 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=6 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=40 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=7 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=48 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=9 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=64 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=10 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=72 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=11 rxpkt=0 txpkt=1 errflags=0x8000d9 rxerr=0 txerr=80 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=13 rxpkt=0 txpkt=1 errflags=0x8440d9 rxerr=0 txerr=96 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=14 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=104 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=15 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=112 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=18 rxpkt=0 txpkt=1 errflags=0x204000 rxerr=0 txerr=128 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
E (32819) can: can1: intr=19 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=128 rxovr=0 txovr=0 txdelay=0 wdgreset=0 errreset=0
D (38479) websocket: new WebSocket slot 2, registered modifier is 3, reader 4
V (38479) websocket: WebSocketHandler[0x3f84aab4] init: handler=0x3f84a228 modifier=3
D (38489) websocket: WebSocket[0x3f84aab4] handler 0x3f84a228 opened; 3 clients active
D (38489) events: Signal(server.web.socket.opened)
I (39499) webserver: HTTP GET /
D (39549) websocket: WebSocket[0x3f84aab4] handler 0x3f84a228 closed; 2 clients active
D (39559) events: Signal(server.web.socket.closed)
I (39599) webserver: HTTP GET /edit
I (39639) webserver: HTTP POST /api/execute
I (39659) webcommand: HttpCommandStream[0x3f845fec]: 3973212 bytes free, executing: vfs ls '/store'
V (41449) websocket: WebSocketHandler[0x3f846c74] init: handler=0x3f846e30 modifier=3
D (41459) websocket: WebSocket[0x3f846c74] handler 0x3f846e30 opened; 3 clients active
D (41459) events: Signal(server.web.socket.opened)
D (60839) script: Duktape: Compacting DukTape memory
D (63819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (63819) can: can1: intr=115562 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=128 rxovr=0 txovr=0 txdelay=1 wdgreset=0 errreset=0
D (94819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
E (94819) can: can1: intr=231228 rxpkt=0 txpkt=1 errflags=0x8040d9 rxerr=0 txerr=128 rxovr=0 txovr=0 txdelay=2 wdgreset=0 errreset=0
E (106869) can: can1: intr=276186 rxpkt=0 txpkt=1 errflags=0x80401a rxerr=0 txerr=136 rxovr=0 txovr=0 txdelay=2 wdgreset=0 errreset=0
D (120829) script: Duktape: Compacting DukTape memory
D (125819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
I (125829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (125829) vehicle: Receive Poll Response for 34/1e3b
D (125829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
I (125829) vwup.obd: Setting car state to ON
V (125829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
D (126819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (126819) vwup.obd: CarOffTicker increased to 1
I (126829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (126829) vehicle: Receive Poll Response for 34/1e3b
D (126829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (126829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (127819) vwup.obd: CarOffTicker increased to 1
V (128819) vwup.obd: CarOffTicker increased to 2
V (129819) vwup.obd: CarOffTicker increased to 3
V (130819) vwup.obd: CarOffTicker increased to 4
V (131819) vwup.obd: CarOffTicker increased to 5
D (132819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (132819) vwup.obd: CarOffTicker increased to 6
I (132829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (132829) vehicle: Receive Poll Response for 34/1e3b
D (132829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (132829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (133819) vwup.obd: CarOffTicker increased to 1
V (134819) vwup.obd: CarOffTicker increased to 2
V (135819) vwup.obd: CarOffTicker increased to 3
V (136819) vwup.obd: CarOffTicker increased to 4
V (137819) vwup.obd: CarOffTicker increased to 5
D (138819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (138819) vwup.obd: CarOffTicker increased to 6
I (138829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (138829) vehicle: Receive Poll Response for 34/1e3b
D (138829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (138829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (139819) vwup.obd: CarOffTicker increased to 1
V (140819) vwup.obd: CarOffTicker increased to 2
V (141819) vwup.obd: CarOffTicker increased to 3
V (142819) vwup.obd: CarOffTicker increased to 4
V (143819) vwup.obd: CarOffTicker increased to 5
D (144819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (144819) vwup.obd: CarOffTicker increased to 6
I (144829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (144829) vehicle: Receive Poll Response for 34/1e3b
D (144829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (144829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (145819) vwup.obd: CarOffTicker increased to 1
V (146819) vwup.obd: CarOffTicker increased to 2
V (147819) vwup.obd: CarOffTicker increased to 3
V (148819) vwup.obd: CarOffTicker increased to 4
V (149819) vwup.obd: CarOffTicker increased to 5
D (150819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (150819) vwup.obd: CarOffTicker increased to 6
E (150819) can: can1: intr=276200 rxpkt=5 txpkt=10 errflags=0x204c00 rxerr=0 txerr=127 rxovr=0 txovr=0 txdelay=2 wdgreset=0 errreset=0
I (150829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (150829) vehicle: Receive Poll Response for 34/1e3b
D (150829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (150829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (151819) vwup.obd: CarOffTicker increased to 1
V (152819) vwup.obd: CarOffTicker increased to 2
V (153819) vwup.obd: CarOffTicker increased to 3
V (154819) vwup.obd: CarOffTicker increased to 4
V (155819) vwup.obd: CarOffTicker increased to 5
D (156819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (156819) vwup.obd: CarOffTicker increased to 6
V (157819) vwup.obd: CarOffTicker increased to 7
V (158819) vwup.obd: CarOffTicker increased to 8
V (159819) vwup.obd: CarOffTicker increased to 9
V (160819) vwup.obd: CarOffTicker increased to 10
V (161819) vwup.obd: CarOffTicker increased to 11
D (162819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (162819) vwup.obd: CarOffTicker increased to 12
V (163819) vwup.obd: CarOffTicker increased to 13
V (164819) vwup.obd: CarOffTicker increased to 14
V (165819) vwup.obd: CarOffTicker increased to 15
V (166819) vwup.obd: CarOffTicker increased to 16
V (167819) vwup.obd: CarOffTicker increased to 17
D (168819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (168819) vwup.obd: CarOffTicker increased to 18
V (169819) vwup.obd: CarOffTicker increased to 19
V (170819) vwup.obd: CarOffTicker increased to 20
V (171819) vwup.obd: CarOffTicker increased to 21
I (172819) vwup.obd: Setting car state to OFF
D (173819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
I (173829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (173829) vehicle: Receive Poll Response for 34/1e3b
D (173829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
I (173829) vwup.obd: Setting car state to ON
V (173829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
D (174819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (174819) vwup.obd: CarOffTicker increased to 1
I (174829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (174829) vehicle: Receive Poll Response for 34/1e3b
D (174829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (174829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (175819) vwup.obd: CarOffTicker increased to 1
V (176819) vwup.obd: CarOffTicker increased to 2
V (177819) vwup.obd: CarOffTicker increased to 3
V (178819) vwup.obd: CarOffTicker increased to 4
V (179819) vwup.obd: CarOffTicker increased to 5
D (180819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (180819) vwup.obd: CarOffTicker increased to 6
D (180839) script: Duktape: Compacting DukTape memory
V (181819) vwup.obd: CarOffTicker increased to 7
V (182819) vwup.obd: CarOffTicker increased to 8
V (183819) vwup.obd: CarOffTicker increased to 9
V (184819) vwup.obd: CarOffTicker increased to 10
V (185819) vwup.obd: CarOffTicker increased to 11
D (186819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (186819) vwup.obd: CarOffTicker increased to 12
V (187819) vwup.obd: CarOffTicker increased to 13
V (188819) vwup.obd: CarOffTicker increased to 14
V (189819) vwup.obd: CarOffTicker increased to 15
V (190819) vwup.obd: CarOffTicker increased to 16
V (191819) vwup.obd: CarOffTicker increased to 17
D (192819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (192819) vwup.obd: CarOffTicker increased to 18
V (193819) vwup.obd: CarOffTicker increased to 19
V (194819) vwup.obd: CarOffTicker increased to 20
V (195819) vwup.obd: CarOffTicker increased to 21
I (196819) vwup.obd: Setting car state to OFF
D (197819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
I (197829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (197829) vehicle: Receive Poll Response for 34/1e3b
D (197829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
I (197829) vwup.obd: Setting car state to ON
V (197829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
D (198819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (198819) vwup.obd: CarOffTicker increased to 1
I (198829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (198829) vehicle: Receive Poll Response for 34/1e3b
D (198829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (198829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (199819) vwup.obd: CarOffTicker increased to 1
V (200819) vwup.obd: CarOffTicker increased to 2
V (201819) vwup.obd: CarOffTicker increased to 3
V (202819) vwup.obd: CarOffTicker increased to 4
V (203819) vwup.obd: CarOffTicker increased to 5
D (204819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (204819) vwup.obd: CarOffTicker increased to 6
V (205819) vwup.obd: CarOffTicker increased to 7
V (206819) vwup.obd: CarOffTicker increased to 8
V (207819) vwup.obd: CarOffTicker increased to 9
V (208819) vwup.obd: CarOffTicker increased to 10
V (209819) vwup.obd: CarOffTicker increased to 11
D (210819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (210819) vwup.obd: CarOffTicker increased to 12
V (211819) vwup.obd: CarOffTicker increased to 13
V (212819) vwup.obd: CarOffTicker increased to 14
V (213819) vwup.obd: CarOffTicker increased to 15
V (214819) vwup.obd: CarOffTicker increased to 16
V (215819) vwup.obd: CarOffTicker increased to 17
D (216819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (216819) vwup.obd: CarOffTicker increased to 18
V (217819) vwup.obd: CarOffTicker increased to 19
V (218819) vwup.obd: CarOffTicker increased to 20
V (219819) vwup.obd: CarOffTicker increased to 21
I (220819) vwup.obd: Setting car state to OFF
D (221819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
I (221829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (221829) vehicle: Receive Poll Response for 34/1e3b
D (221829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
I (221829) vwup.obd: Setting car state to ON
V (221829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
D (222819) vehicle: Polling for 34/1e3b (expecting 7e5/7ed-7ed)
V (222819) vwup.obd: CarOffTicker increased to 1
I (222829) vehicle: Poller Rx candidate ID=7ed (expecting 7ed-7ed)
I (222829) vehicle: Receive Poll Response for 34/1e3b
D (222829) vwup.obd: IncomingPollReply(type=34, pid=1E3B, length=4, remain=0): called
V (222829) vwup.obd: StandardMetrics.ms_v_bat_voltage=333.500000
V (223819) vwup.obd: CarOffTicker increased to 1