[Ovmsdev] Console logging / CAN tracing

[Michael Balzer]

Stephen,

can you take a look at my mitigation of the queue blocking issue?

https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/commit/b08e70497158bd2473e02c8912271627c4bb71b6

If a console currently executes a command, I lower the log queueing wait time to 0. Other consoles continue normal log processing, so I can for example issue
commands on the telnet console and watch their log output on the async.

Regards,
Michael


Am 29.12.2017 um 23:04 schrieb Stephen Casner:
> Michael,
>
> The right fix is to change the CAN tracing to gather its output into a
> buffer so complete lines get logged.
>
> The ESP_LOG macros get redirected through our logging system as well,
> but (currently) only to the async console rather than all consoles.
> Is logging of CAN traces to telnet/SSH sessions desired?  How about
> other logging?
>
> There may also be some ways to improve handling of full-queue
> conditions to degrade more gracefully.
>
>                                                         -- Steve
>
> On Fri, 29 Dec 2017, Michael Balzer wrote:
>
>> I've found a strange issue with console logging and/or especially
>> CAN tracing:
>>
>> If CAN tracing is enabled and a and that sends CAN frames and runs
>> longer than about a second (?) (i.e. "co can1 scan"), the trace
>> output first becomes garbled, the command will need much longer than
>> usual to finish, and after returning to the prompt, the hex and
>> single char output of the trace is split into separate outputs,
>> coming one per second (running for a while), intermixing with the
>> shell prompt. Also trace output gets garbled especially on a
>> parallel telnet session.
>>
>> I suspect that's due to the UART queue becoming full, and the
>> console logger doing xQueueSendToBack() with 1000 ms timeouts.
>>
>> Every hex dump byte is logged by a separate call to
>> MyCommandApp.Log(). If the queue is full, every single call gets
>> delayed for a second ...adding up to block the console for as many
>> seconds as there are calls...? (unverified theory)
>>
>>> As proposed, I will change the script code to use BufferedShell and
>>> also change how console_logger() is done so I can remove the
>>> problematic OvmsConsole::Log() function.  Then puts() will work again,
>>> too.
>>>                                                         -- Steve
>> Is this related? I.e. should the CAN trace output be done using
>> ESP_LOG instead of MyCommandApp.Log()?
>>
>> If so I can take care of that...
>>
>> Regards,
>> Michael
>>
>> --
>> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
>> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.teslaclub.hk
> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26