Mark, is there a bug in the new can monitoring or am I doing something wrong? monitor mode: OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle:RT Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (83919) canlog-monitor: Now logging CAN messages to monitor D (83919) canlog-monitor: 1564312407.926444 CXX OVMS CRTD OVMS# can can1 tx standard 080 010203 ets Jun 8 2016 00:22:57 rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x4009621a vfs mode: OVMS# can log start vfs crtd /sd/logs/can.crtd ets Jun 8 2016 00:22:57 rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x400838cc Regards, Michael -- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
Michael, Not sure what is going on. Here is what I get: OVMS# log level verbose Logging level for * set to verbose OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle: Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (58794) canlog-monitor: Now logging CAN messages to monitor D (58794) canlog-monitor: 1564318162.354891 CXX OVMS CRTD OVMS# can can1 start active 1000000 Can bus can1 started in mode active at speed 1000000bps D (68894) events: Signal(power.can1.on) OVMS# can can2 start active 1000000 Can bus can2 started in mode active at speed 1000000bps D (73774) events: Signal(power.can2.on) OVMS# can can1 tx standard 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.493753 1T11 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.494240 2R11 080 01 02 03 04 OVMS# can can1 tx standard 080 010203 V (108364) canlog-monitor: 1564318211.923843 1T11 080 03 V (108364) canlog-monitor: 1564318211.924243 2R11 080 03 Did you get a backtrace? Regards, Mark P.S. The data bytes in ‘can tx’ need to be space separated. Without that, it messed up the data, but still works for me.
On 28 Jul 2019, at 7:27 PM, Michael Balzer <dexter@expeedo.de> wrote:
Mark,
is there a bug in the new can monitoring or am I doing something wrong?
monitor mode: OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle:RT Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (83919) canlog-monitor: Now logging CAN messages to monitor D (83919) canlog-monitor: 1564312407.926444 CXX OVMS CRTD OVMS# can can1 tx standard 080 010203 ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x4009621a
vfs mode: OVMS# can log start vfs crtd /sd/logs/can.crtd ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x400838cc
Regards, Michael
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26 _______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com http://lists.openvehicles.com/mailman/listinfo/ovmsdev
I tried some more. It seems that the problem is with logging errors in crtd format. I didn’t see it because my bus had no errors. Seems to be just a simple buffer overflow. I’ve committed a fix. Regards, Mark. P.S. I have a relatively big update to can logging going through testing. Some standardisation of functionality for incoming data (such as whether to transmit or simulate it), and a can log playback system.
On 28 Jul 2019, at 8:52 PM, Mark Webb-Johnson <mark@webb-johnson.net> wrote:
Michael,
Not sure what is going on. Here is what I get:
OVMS# log level verbose Logging level for * set to verbose OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle: Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (58794) canlog-monitor: Now logging CAN messages to monitor D (58794) canlog-monitor: 1564318162.354891 CXX OVMS CRTD OVMS# can can1 start active 1000000 Can bus can1 started in mode active at speed 1000000bps D (68894) events: Signal(power.can1.on) OVMS# can can2 start active 1000000 Can bus can2 started in mode active at speed 1000000bps D (73774) events: Signal(power.can2.on) OVMS# can can1 tx standard 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.493753 1T11 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.494240 2R11 080 01 02 03 04 OVMS# can can1 tx standard 080 010203 V (108364) canlog-monitor: 1564318211.923843 1T11 080 03 V (108364) canlog-monitor: 1564318211.924243 2R11 080 03
Did you get a backtrace?
Regards, Mark
P.S. The data bytes in ‘can tx’ need to be space separated. Without that, it messed up the data, but still works for me.
On 28 Jul 2019, at 7:27 PM, Michael Balzer <dexter@expeedo.de <mailto:dexter@expeedo.de>> wrote:
Mark,
is there a bug in the new can monitoring or am I doing something wrong?
monitor mode: OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle:RT Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (83919) canlog-monitor: Now logging CAN messages to monitor D (83919) canlog-monitor: 1564312407.926444 CXX OVMS CRTD OVMS# can can1 tx standard 080 010203 ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x4009621a
vfs mode: OVMS# can log start vfs crtd /sd/logs/can.crtd ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x400838cc
Regards, Michael
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26 _______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com <mailto:OvmsDev@lists.openvehicles.com> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
_______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com http://lists.openvehicles.com/mailman/listinfo/ovmsdev
Yes, that solved it, thanks! Regards, Michael Am 28.07.19 um 15:10 schrieb Mark Webb-Johnson:
I tried some more. It seems that the problem is with logging errors in crtd format. I didn’t see it because my bus had no errors.
Seems to be just a simple buffer overflow. I’ve committed a fix.
Regards, Mark.
P.S. I have a relatively big update to can logging going through testing. Some standardisation of functionality for incoming data (such as whether to transmit or simulate it), and a can log playback system.
On 28 Jul 2019, at 8:52 PM, Mark Webb-Johnson <mark@webb-johnson.net <mailto:mark@webb-johnson.net>> wrote:
Michael,
Not sure what is going on. Here is what I get:
OVMS# log level verbose Logging level for * set to verbose OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle: Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (58794) canlog-monitor: Now logging CAN messages to monitor D (58794) canlog-monitor: 1564318162.354891 CXX OVMS CRTD OVMS# can can1 start active 1000000 Can bus can1 started in mode active at speed 1000000bps D (68894) events: Signal(power.can1.on) OVMS# can can2 start active 1000000 Can bus can2 started in mode active at speed 1000000bps D (73774) events: Signal(power.can2.on) OVMS# can can1 tx standard 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.493753 1T11 080 01 02 03 04 V (96934) canlog-monitor: 1564318200.494240 2R11 080 01 02 03 04 OVMS# can can1 tx standard 080 010203 V (108364) canlog-monitor: 1564318211.923843 1T11 080 03 V (108364) canlog-monitor: 1564318211.924243 2R11 080 03
Did you get a backtrace?
Regards, Mark
P.S. The data bytes in ‘can tx’ need to be space separated. Without that, it messed up the data, but still works for me.
On 28 Jul 2019, at 7:27 PM, Michael Balzer <dexter@expeedo.de <mailto:dexter@expeedo.de>> wrote:
Mark,
is there a bug in the new can monitoring or am I doing something wrong?
monitor mode:
OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd Filter:off Vehicle:RT Note: info logging is at debug log level, frame logging is at verbose, and errors as usual I (83919) canlog-monitor: Now logging CAN messages to monitor D (83919) canlog-monitor: 1564312407.926444 CXX OVMS CRTD OVMS# can can1 tx standard 080 010203 ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x4009621a
vfs mode:
OVMS# can log start vfs crtd /sd/logs/can.crtd ets Jun 8 2016 00:22:57
rst:0x8 (TG1WDT_SYS_RESET),boot:0x3b (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:4952 load:0x40078000,len:7416 load:0x40080000,len:8344 entry 0x4008037c W (86) boot: PRO CPU has been reset by WDT. W (86) boot: WDT reset info: PRO CPU PC=0x4008aab8 W (86) boot: WDT reset info: APP CPU PC=0x400838cc
Regards, Michael
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26 _______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com <mailto:OvmsDev@lists.openvehicles.com> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
_______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com <mailto:OvmsDev@lists.openvehicles.com> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
_______________________________________________ OvmsDev mailing list OvmsDev@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
On 2019-07-28 04:10, Mark Webb-Johnson wrote:
I tried some more. It seems that the problem is with logging errors in crtd format. I didn’t see it because my bus had no errors.
Seems to be just a simple buffer overflow. I’ve committed a fix.
Regards, Mark.
P.S. I have a relatively big update to can logging going through testing. Some standardisation of functionality for incoming data (such as whether to transmit or simulate it), and a can log playback system.
Would it be ok to stop using sprintf() completely? Personally I try and use snprintf() and strlcpy() instead of sprintf() and strcpy(). Craig
Craig, We don’t really have a good solution for this, and to me the c++ classes are very lacking. It seems simple to want to sprintf to a std::string in an efficient manner, but there is no such functionality. The output string buffer we use works ok (although imho more cumbersome than sprintf), but is a huge overhead. For can logging, I was trying to keep things as lightweight and efficient as possible. We would like to be able to process thousands of messages a second, so every bit of optimisation helps here. The current crtd implementation was just a simple port of what we had before, and definitely needs improvements. For example, using sprintf for those data byte output in hex is simple but slow. It would much faster to have a lookup table of 0->15 mapping to 0-9,a-f, and index that with number / 16, number % 16 (or number >> 4, and number & 0x0f). I have made a change to the canformat_crtd to use snprintf (rather than sprintf) in most places - just the data byte sprintf left in two places. But the issue is bigger - 995 results in 141 files when searching the project for ’sprintf’ (most not in our code, but in third party libraries). If someone has the time to review and improve where appropriate, I would be happy to accept. But we need to be very careful when this is changed to ensure the change doesn’t break something. No regression testing, so any impact might be hard to find. Regards, Mark.
On 29 Jul 2019, at 12:54 AM, Craig Leres <leres@xse.com> wrote:
On 2019-07-28 04:10, Mark Webb-Johnson wrote:
I tried some more. It seems that the problem is with logging errors in crtd format. I didn’t see it because my bus had no errors. Seems to be just a simple buffer overflow. I’ve committed a fix. Regards, Mark. P.S. I have a relatively big update to can logging going through testing. Some standardisation of functionality for incoming data (such as whether to transmit or simulate it), and a can log playback system.
Would it be ok to stop using sprintf() completely? Personally I try and use snprintf() and strlcpy() instead of sprintf() and strcpy().
Craig
participants (3)
-
Craig Leres -
Mark Webb-Johnson -
Michael Balzer