Running CAN-BUS Sample with different shield (NRF52840DK & Seeed CAN BUS Shield V2.0)

[ejromero2]

Hi All, 

Im very new to this how firmware space and would love some help.

Currently i have a NRF52840 DK Board with a Seeed Canbus shield. (CAN-BUS Shield V2.0 | Seeed Studio Wiki)

From what i have read is very similar to the DFROBOT CanBus Shield. (Only changing the default pinout for the CS from D10 to D9)

- I have been able to succesfully comple and flash the firmware but i get the following error :

Error starting CAN controller [-5]

I have tried modifying the dfrobot_can_bus_v2_0.overlay to make it work with my seeed shield.  (changing the CS-GPIOS to 15 (D9) instead of 16 (D10).

The error remains the same, and i dont really know how to get a little bit more information to progress on this.

Im trying to run this sample: zephyr/samples/drivers/can/counter at main · zephyrproject-rtos/zephyr (github.com)

[ovrebekk]

Hi Efrain

Error -5 means there is some communication issue with the board. 

Do you know if the board is able to run at 3V? 
The supply and GPIO voltage of the nRF52840DK is around 3V, while many Arduino shields require 5V supply. 

Have you probed the SPI lines to see if there is any activity when the code runs? 
If not it could point to some configuration issue in your project. 

Could you share the overlay with me? 

Best regards
Torbjørn

[ejromero2]

Hi there,

Thanks for the answer:

I only changed the cs-pios to 15 to make it in line with the seeed information.

/*
 * Copyright (c) 2019 Karsten Koenig
 *
 * SPDX-License-Identifier: Apache-2.0
 */

&arduino_spi {
	status = "okay";
	cs-gpios = <&arduino_header 15 GPIO_ACTIVE_LOW>; /* D9 */

	mcp2515_dfrobot_can_bus_v2_0: can@0 {
		compatible = "microchip,mcp2515";
		spi-max-frequency = <1000000>;
		int-gpios = <&arduino_header 8 GPIO_ACTIVE_LOW>; /* D2 */
		status = "okay";
		reg = <0x0>;
		osc-freq = <16000000>;
		bus-speed = <125000>;
		sjw = <1>;
		sample-point = <875>;

		can-transceiver {
			max-bitrate = <1000000>;
		};
	};
};




/ {
	chosen {
		zephyr,canbus = &mcp2515_dfrobot_can_bus_v2_0;
	};
};

I get the following logging info:

[00:00:00.476,654] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
uart:~$ Error starting CAN control--- 431 messages dropped ---
[00:00:00.499,145] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.499,176] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.499,206] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.499,237] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.499,389] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.499,420] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.499,481] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.499,511] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.499,542] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.499,572] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.499,603] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.499,755] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.499,786] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.499,847] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.499,877] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.499,908] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.499,938] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.499,969] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.500,122] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.500,152] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.500,213] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.500,244] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.500,274] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.500,305] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.500,335] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.500,518] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.500,549] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.500,579] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.500,610] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.500,640] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.500,671] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.500,701] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.500,885] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.500,915] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.500,946] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.500,976] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.501,037] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.501,037] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.501,068] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.501,251] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.501,281] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.501,312] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.501,342] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.501,403] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.501,403] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.501,434] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.501,617] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.501,647] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.501,678] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.501,708] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.501,770] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.501,770] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.501,800] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.501,983] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.502,014] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.502,075] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.502,105] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.502,136] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.502,166] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.502,197] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.502,349] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.502,410] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.502,441] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.502,471] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.502,502] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.502,532] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.502,563] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.502,777] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.502,807] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.502,838] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.502,868] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.502,899] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.502,929] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.502,960] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.503,112] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.503,173] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.503,204] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.503,234] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.503,265] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.503,295] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.503,326] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.503,540] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.503,570] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.503,601] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.503,631] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.503,662] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.503,692] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.503,723] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.503,875] <dbg> spi_nrfx_spi: spi_context_buffers_setup: tx_bufs 0x20004838 - rx_bufs 0x20004840 - 1
[00:00:00.503,936] <dbg> spi_nrfx_spi: spi_context_buffers_setup: current_tx 0x20004848 (2), current_rx 0x20004858 (2), tx buf/len 0x20004834/2, rx buf/len (nil)/2
[00:00:00.503,967] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/1
[00:00:00.503,997] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len 0x2000487f/1
[00:00:00.504,058] <dbg> spi_nrfx_spi: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.504,089] <dbg> spi_nrfx_spi: spi_context_update_rx: rx buf/len (nil)/0
[00:00:00.504,089] <dbg> spi_nrfx_spi: finish_transaction: Transaction finished with status 0
[00:00:00.504,150] <err> can_mcp2515: Timeout trying to set MCP2515 operation mode
[00:00:00.504,180] <err> can_mcp2515: Failed to set the mode [-5]
uart:~$

im not quite sure about the power question.  i have tried to put some extra sensors on the 3.3 output of the shield and that sensor works just fine. (but then again im guessing is just the direct line from the nrf).

[ovrebekk]

Hi Efrain

If there is no working communication between the nRF device and the MCP2515 it makes sense that the log output would be the same. It seems the new shield is also using 5V supply. 

I think it is hard to debug this further without the ability to scope the SPI lines, and some way of adjusting the supply voltage on the CAN shield in order to be compatible with the nRF device. 

Like I said I am happy to order a shield and do some testing on my own, but this will take some time. 

Best regards
Torbjørn

[ejromero2]

hI Torbjørn

I think it could be awsome if you get a can shield (please le me know which one so that i can order the same :) ).

Now with that said i have made some "progress"

Since there was soo much code in the "sample" i cut it down to a simpler one:

//Pretty standar code to recieve frames and send an OBD2 CanFrame

/*
 * Copyright (c)
 *
 * SPDX-License-Identifier: Apache-2.0
 */

#include <zephyr/drivers/can.h>
#include <zephyr/logging/log.h>
LOG_MODULE_REGISTER(main);

void tx_callback(const struct device *dev, int error, void *user_data)
{
	char *sender = (char *)user_data;

	if (error != 0) {
		LOG_ERR("Sending failed [%d] - Sender: %s", error, sender);
	}
}

int send_function(const struct device *can_dev)
{
	struct can_frame frame = {.flags = 0, .id = 0x7df, .dlc = 8, .data = {0x02, 0x01, 0x0c}};

	// frame.data[0] = 1;
	// frame.data[1] = 2;

	return can_send(can_dev, &frame, K_MSEC(2000), tx_callback, "Sender 1");
}

void rx_callback_function(const struct device *dev, struct can_frame *frame, void *user_data)
{
	char *sender = (char *)user_data;

	LOG_INF("ID: 0x%x\n", frame->id);
	printk("Received CAN frame\nSender: %s\n", sender);
	printk("ID: 0x%x\n", frame->id);
	printk("DLC: %d\n", frame->dlc);
	printk("Data: ");
	printk("0x%x ", frame->data[0]);
	printk("0x%x ", frame->data[1]);
	printk("0x%x ", frame->data[2]);
	printk("0x%x ", frame->data[3]);
	printk("0x%x ", frame->data[4]);
	printk("0x%x ", frame->data[5]);
	printk("0x%x ", frame->data[6]);
	printk("0x%x ", frame->data[7]);
	printk("\n");
}

int main(void)
{
	LOG_INF("CanBus-OBD2 samplev11");
	int ret;
	k_sleep(K_MSEC(8000));

	const struct device *const can_dev = DEVICE_DT_GET(DT_CHOSEN(zephyr_canbus));

	LOG_INF("Asserting device ready.");
	if (!device_is_ready(can_dev)) {
		LOG_ERR("CAN: Device %s not ready.", can_dev->name);
		return 0;
	}
	LOG_INF("CAN: Device %s ready.", can_dev->name);

	LOG_INF("Enabling MODE NORMAL.");
	ret = can_set_mode(can_dev, CAN_MODE_NORMAL);
	if (ret != 0) {
		LOG_ERR("Error setting CAN mode [%d]", ret);
		return 0;
	}
	LOG_INF("MODE NORMAL Enabled.");

	LOG_INF("Trying to set bitrate.");
	ret = can_set_bitrate(can_dev, 500000);
	if (ret != 0) {
		LOG_ERR("Error setting CAN bitrate [%d]", ret);
		return 0;
	}
	LOG_INF("Set bitrate.");

	LOG_INF("Trying to start CAN.");
	ret = can_stop(can_dev);
	if (ret != 0) {
		LOG_ERR("Error stop CAN controller [%d]", ret);
		// return 0;
	}
	LOG_INF("CAN stopped [%d]", ret);

	LOG_INF("Trying to start can.");
	ret = can_start(can_dev);
	if (ret != 0) {
		LOG_ERR("Error starting CAN controller [%d]", ret);
		return 0;
	}
	LOG_INF("CAN started");

	const struct can_filter my_filter = {
		.flags = CAN_FILTER_DATA, .id = 0x7E8, .mask = CAN_STD_ID_MASK};
	int filter_id;

	char *callback_arg = "Callback argument";

	filter_id = can_add_rx_filter(can_dev, rx_callback_function, callback_arg, &my_filter);
	if (filter_id < 0) {
		LOG_ERR("Unable to add rx filter [%d]", filter_id);
	}

	printk("Filter ID: %d\n", filter_id);

	while (1) {
		LOG_INF("Waiting for CAN frame");
		k_sleep(K_MSEC(1000));
		LOG_INF("Sending CAN frame");
		ret = send_function(can_dev);
		if (ret != 0) {
			LOG_ERR("Sending failed [%d]", ret);
		} else {
			LOG_INF("CAN frame sent");
		}
	}
}

Now (both Shields The "seeed" and the "keystudio" seem to "boot up"

And i get the following log:

[00:00:00.251,617] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000aca8 - rx_bufs (nil) - 1
[00:00:00.251,617] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac9c (1), current_rx (nil) (0), tx buf/len 0x2000ac98/1, rx buf/len (nil)/0
[00:00:00.251,678] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.251,708] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:00.251,800] <dbg> can_mcp2515: mcp2515_init: Presc: 4, BS1: 7, BS2: 2
[00:00:00.251,800] <dbg> can_mcp2515: mcp2515_init: Sample-point err : 0
[00:00:00.252,044] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac48 - rx_bufs (nil) - 1
[00:00:00.252,075] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac50 (2), current_rx (nil) (0), tx buf/len 0x2000ac40/2, rx buf/len (nil)/0
[00:00:00.252,136] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len 0x2000ac44/4
[00:00:00.252,197] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.252,197] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:00.252,227] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac30 - rx_bufs (nil) - 1
[00:00:00.252,258] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac28 (1), current_rx (nil) (0), tx buf/len 0x2000ac24/4, rx buf/len (nil)/0
[00:00:00.252,319] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.252,349] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:00.252,380] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac30 - rx_bufs (nil) - 1
[00:00:00.252,410] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac28 (1), current_rx (nil) (0), tx buf/len 0x2000ac24/4, rx buf/len (nil)/0
[00:00:00.252,471] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:00.252,471] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
*** Booting Zephyr OS build v3.3.99-ncs1 ***
[00:00:00.252,563] <inf> main: CanBus-OBD2 samplev11
[00:00:08.252,624] <inf> main: Asserting device ready.
[00:00:08.252,685] <inf> main: CAN: Device can@0 ready.
[00:00:08.252,685] <inf> main: Enabling MODE NORMAL.
[00:00:08.252,716] <inf> main: MODE NORMAL Enabled.
[00:00:08.252,716] <inf> main: Trying to set bitrate.
[00:00:08.252,746] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac60 - rx_bufs (nil) - 1
[00:00:08.252,777] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac68 (2), current_rx (nil) (0), tx buf/len 0x2000ac58/2, rx buf/len (nil)/0
[00:00:08.252,838] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len 0x2000ac5c/4
[00:00:08.252,899] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:08.252,899] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:08.252,960] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac48 - rx_bufs (nil) - 1
[00:00:08.252,990] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac40 (1), current_rx (nil) (0), tx buf/len 0x2000ac3c/4, rx buf/len (nil)/0
[00:00:08.253,051] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:08.253,051] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:08.253,082] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac48 - rx_bufs (nil) - 1
[00:00:08.253,112] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac40 (1), current_rx (nil) (0), tx buf/len 0x2000ac3c/4, rx buf/len (nil)/0
[00:00:08.253,173] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:08.253,204] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:08.253,234] <inf> main: Set bitrate.
[00:00:08.253,234] <inf> main: Trying to start CAN.
[00:00:08.253,265] <err> main: Error stop CAN controller [-120]
[00:00:08.253,265] <inf> main: CAN stopped [-120]
[00:00:08.253,295] <inf> main: Trying to start can.
[00:00:08.253,295] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac50 - rx_bufs (nil) - 1
[00:00:08.253,326] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac48 (1), current_rx (nil) (0), tx buf/len 0x2000ac44/4, rx buf/len (nil)/0
[00:00:08.253,387] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:08.253,417] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:08.253,448] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac20 - rx_bufs 0x2000ac28 - 1
[00:00:08.253,479] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac30 (2), current_rx 0x2000ac40 (2), tx buf/len 0x2000ac1c/2, rx buf/len (nil)/2
[00:00:08.253,509] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/1
[00:00:08.253,540] <dbg> spi_nrfx_spim: spi_context_update_rx: rx buf/len 0x2000ac67/1
[00:00:08.253,570] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:08.253,570] <dbg> spi_nrfx_spim: spi_context_update_rx: rx buf/len (nil)/0
[00:00:08.253,601] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:08.253,631] <inf> main: CAN started
Filter ID: 0
[00:00:08.253,662] <inf> main: Waiting for CAN frame
[00:00:09.253,753] <inf> main: Sending CAN frame
[00:00:09.253,814] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac40 - rx_bufs (nil) - 1
[00:00:09.253,814] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac58 (2), current_rx (nil) (0), tx buf/len 0x2000ac3c/1, rx buf/len (nil)/0
[00:00:09.253,875] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len 0x2000ac48/13
[00:00:09.254,028] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:09.254,028] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:09.254,089] <dbg> spi_nrfx_spim: spi_context_buffers_setup: tx_bufs 0x2000ac58 - rx_bufs (nil) - 1
[00:00:09.254,089] <dbg> spi_nrfx_spim: spi_context_buffers_setup: current_tx 0x2000ac40 (1), current_rx (nil) (0), tx buf/len 0x2000ac3c/1, rx buf/len (nil)/0
[00:00:09.254,150] <dbg> spi_nrfx_spim: spi_context_update_tx: tx buf/len (nil)/0
[00:00:09.254,180] <dbg> spi_nrfx_spim: finish_transaction: Transaction finished with status 0
[00:00:09.254,211] <inf> main: CAN frame sent
[00:00:09.254,211] <inf> main: Waiting for CAN frame
[00:00:10.254,302] <inf> main: Sending CAN frame
[00:00:12.254,425] <err> main: Sending failed [-11]
[00:00:12.254,455] <inf> main: Waiting for CAN frame
[00:00:13.254,608] <inf> main: Sending CAN frame
[00:00:15.254,699] <err> main: Sending failed [-11]
[00:00:15.254,730] <inf> main: Waiting for CAN frame
[00:00:16.254,882] <inf> main: Sending CAN frame
[00:00:18.254,974] <err> main: Sending failed [-11]

Any ideas?

[ovrebekk]

Hi Efrain

I ordered a couple of the Seeed Studio CAN shields, so no need for you to order anything

It is interesting to see that you got something working finally. 

The sending failed -11 error is probably coming from here, which indicates that something is wrong with the TX callback since the tx_sem semaphore should be given in the tx_done callback here.

Could you add some logging in your tx_callback(..) function to verify that this function is actually called after you call can_send(..) ? 

Best regards
Torbjørn

[ejromero2]

I haven forgotten about this. ill try to test it tomorrow and report back.

[ovrebekk]

No worries, just let me know when you have been able to test it. 

I am still waiting for the shields I ordered, so there's nothing new to report from my side. 

Regards
Torbjørn

[ejromero2]

hi there! did you had any luck with your shields? 

[ovrebekk]

Hi 

By coincidence I just received them yesterday! Not sure why it took so long...

Unfortunately I am stuck with another project until the end of next week, so I won't be able to look into this until the week of November 5th. 

Best regards
Torbjørn

[ejromero2]

Almost there then :)

[ovrebekk]

Fingers crossed I will be able to reproduce the issue, and find a solution ;)

Did you discover anything else in the mean time that might be helpful to know? 

Best regards
Torbjørn

[ejromero2]

No really. to be honest i stopped trying because my results were not the same and to me it seems its related to spi communication and i dont really know how to properly debug it.