[Ovmsdev] Console logging / CAN tracing

[Stephen Casner]

Michael,

No, I would prefer to remove this "busy" mechanism that you added
because it does not serve any useful purpose.  During the time that
"busy" would be false the probability of the queue becoming full is
very low because the amount of processing in the command parser
itself is small, so it makes no difference whether the wait
time is 0 or 1000.  Therefore we might as well set the wait time to
zero always.

Choosing to set the wait time to zero (during a command or not) means
that we choose to discard log messages rather than delaying the
processes that are generating them.  It is fine with me if we want to
make that policy change.  Then I think we should have a counter for
lost log messages and print a warning message about that loss when
control returns to the command parser.  I did that as part of the new
support for commands that take input from the console; while in that
mode, log messages are moved to a separate queue, and when that queue
fills the oldest messages are discarded.

                                                        -- Steve

On Sat, 30 Dec 2017, Michael Balzer wrote:

> 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
>
>
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.teslaclub.hk
> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
>
>