Teletype Firmware i2c Debugging

tehn · 2016-12-27T13:09:17.842Z

some sort of bug crept into the i2c code as i certainly tested all of the mentioned conditions and they worked fine on the initial release of ansible.

i’ll do a review of the code and post a functional review of the approach

tehn · 2016-12-27T16:33:22.781Z

mostly for myself, but in case anyone wants to come along for this debug.

general trace of i2c below. from the lowest level to highest.

lib i2c init: libavr32/src/init_common.c

github.com

monome/libavr32/blob/42461486733bed831d78acc0c464925e919b4a21/src/init_common.c#L70


tc_configure_interrupts(tc, APP_TC_CHANNEL, &tc_interrupt);
// Start the timer/counter.
tc_start(tc, APP_TC_CHANNEL);
}


// initialize USB host stack
void init_usb_host (void) {
uhc_start();
}


// initialize i2c
void init_i2c_master(void) {
twi_options_t opt;


int status;


static const gpio_map_t TWI_GPIO_MAP = {
  {AVR32_TWI_SDA_0_0_PIN, AVR32_TWI_SDA_0_0_FUNCTION},
  {AVR32_TWI_SCL_0_0_PIN, AVR32_TWI_SCL_0_0_FUNCTION}
};

lib i2c functions: libavr32/src/i2c.c

github.com

monome/libavr32/blob/42461486733bed831d78acc0c464925e919b4a21/src/i2c.c

#include "print_funcs.h"
#include "twi.h"
#include "events.h"
#include "i2c.h"

uint8_t rx_buffer[I2C_RX_BUF_SIZE];
static uint8_t rx_pos;

uint8_t tx_buffer[I2C_TX_BUF_SIZE];
static uint8_t tx_pos_read;
static uint8_t tx_pos_write;

static twi_package_t packet;
// static twi_package_t packet_received;

volatile process_ii_t process_ii;


void i2c_master_tx(uint8_t addr, uint8_t *data, uint8_t length) {
  int status;

This file has been truncated. show original

tt i2c send, trilogy: teletype/module/main.c

messages are sent out after being put into a queue
this function is called by the event handler

github.com

monome/teletype/blob/master/module/main.c#L823


flash_update_device_config(&device_config);
}




////////////////////////////////////////////////////////////////////////////////
// teletype_io.h


uint32_t tele_get_ticks() {
return get_ticks();
}


void tele_metro_updated() {
uint32_t metro_time = scene_state.variables.m;


bool m_act = scene_state.variables.m_act;
if (metro_time < METRO_MIN_UNSUPPORTED_MS) {
    metro_time = METRO_MIN_UNSUPPORTED_MS;
}


if (m_act && !metro_timer_enabled) {  // enable the timer
    timer_add(&metroTimer, metro_time, &metroTimer_callback, NULL);

tt spawns ii events at line 1789, called from the teletype engine (ops)

tt i2c send, ansible:

line 845
messages are sent out after being put into a queue
this function is called by the event handler
this is different from the trilogy handler in that it handles variable length i2c messages

events queued from line 1796, called from teletype engine (ops)

line 1820 has a non-queued SEND NOW ii function

line 1824, rx is not queued. it is read immediately.

tt ops: teletype/src/ops/hardware.c

cv SEND

github.com

monome/teletype/blob/master/src/ops/hardware.c#L256


                            command_state_t *NOTUSED(cs)) {
ss_reset_in_cal(ss);
}




static void op_PARAM_get(const void *NOTUSED(data), scene_state_t *ss,
                     exec_state_t *NOTUSED(es), command_state_t *cs) {
tele_update_adc(0);
cs_push(cs, ss_get_param(ss));
}


static void op_PARAM_SCALE_set(const void *NOTUSED(data), scene_state_t *ss,
                           exec_state_t *NOTUSED(es), command_state_t *cs) {
int16_t min = cs_pop(cs);
int16_t max = cs_pop(cs);
ss_set_param_scale(ss, min, max);
}


static void op_PARAM_CAL_MIN_set(const void *NOTUSED(data), scene_state_t *ss,
                             exec_state_t *NOTUSED(es),
                             command_state_t *cs) {

cv RECEIVE

github.com

monome/teletype/blob/master/src/ops/hardware.c#L229


static void op_IN_get(const void *NOTUSED(data), scene_state_t *ss,
                  exec_state_t *NOTUSED(es), command_state_t *cs) {
tele_update_adc(0);
cs_push(cs, ss_get_in(ss));
}


static void op_IN_SCALE_set(const void *NOTUSED(data), scene_state_t *ss,
                        exec_state_t *NOTUSED(es), command_state_t *cs) {
int16_t min = cs_pop(cs);
int16_t max = cs_pop(cs);
ss_set_in_scale(ss, min, max);
}


static void op_IN_CAL_MIN_set(const void *NOTUSED(data), scene_state_t *ss,
                          exec_state_t *NOTUSED(es), command_state_t *cs) {
ss_set_in_min(ss, ss->variables.in);
cs_push(cs, ss->variables.in);
}


static void op_IN_CAL_MAX_set(const void *NOTUSED(data), scene_state_t *ss,
                          exec_state_t *NOTUSED(es), command_state_t *cs) {

ok-- now to tinker

bpcmusic · 2016-12-27T17:24:49.076Z

@tehn thanks for looking into this! Let me know if I can be of any help.

Read Freezing

I have some untested, knuckle-headed theories on the II read in the M event as this has been plaguing my development of the expanders all year. It has been on my to-do list for a while now.

I’m doing essentially the same thing with the reads for the TXi 1.3 code - send a command as to what you would like to poll and then request the value. (I’m only using half of the buffer for the tx_now output setting - the “1” there is intentional.)

https://github.com/bpcmusic/teletype/blob/telex/src/ops/telex.c#L243

Ansible Output Uncertainty in 1.3

I was tinkering around a bit more and identified the following behavior with my output expanders. I have four connected (including my earliest prototype that includes an LED layout goof) and am able to easily address all 16 CV or TR outputs. For these devices, no outputs are being skipped like in the earlier Ansible examples.

I am running into some limits on the number of II events that I can trigger per metronome event. I seem to be able to fire only one line of events - as shown in the video below (using my fork + branch of the TT code). I used to be able to put tons of commands in the M event in the pre 1.3 code that I had extended to support the TELEX devices.

Note: Ignore the LED layout on the far right module. As I said above, that was my first prototype that included a PWM output routing error that put the TR 4 LED below the four CV LEDs. Need to get it out of my demo rig - it always makes me cringe.

Galapagoose · 2016-12-27T21:54:35.469Z

Just a little vote of support & encouragement here! I know some of these issues relate to the Just Type firmware for JF as well, so excited to see things move forward.

On my side, I’ve noticed TT can freeze when sending multiple commands to JF from the same script. The receive code is triggered by interrupt, grabs the data on the i2c line and dumps it in a buffer. That interrupt is on a higher priority IRQ than the audio DSP loop, yet still when the DSP is running a more intensive mode, the freeze (on TT) is more likely – I can’t explain why!

Hope that’s not too OT.

laborcamp · 2016-12-28T00:40:29.245Z

Also words of encouragement from me, hoping for the fix!

I have experienced TT freezing with my trilogy on many occasions in the past, and I never thought that this might have been related to Metro functionality. But now that I think of it it could very well have been the case, especially with Earthsea, when I was hoping to clock it from TT…

bpcmusic · 2016-12-28T18:46:16.669Z

I didn’t mention my half-baked, harebrained theory above for the freezing on read issue. My gut is telling me that the issue is related to a contention between interrupts which causes the TT to miss out on the receipt of the response and sit (relaxed) waiting for it.

I could be biased to think this because I’ve spent a lot of time looking here trying to figure out how to recover from calls to modules that aren’t connected:

github.com

monome/libavr32/blob/master/asf/avr32/drivers/twi/twi.c#L451


		twi->cr = AVR32_TWI_STOP_MASK;
	}


	// mask NACK and RXRDY interrupts
	twi_it_mask = AVR32_TWI_IER_NACK_MASK | AVR32_TWI_IER_RXRDY_MASK;


	// update IMR through IER
	twi->ier = twi_it_mask;


	// get data
	while (twi_is_busy()) {
		cpu_relax();
	}


	// Disable master transfer
	twi->cr =  AVR32_TWI_CR_MSDIS_MASK;


	if (twi_nack) {
		return TWI_RECEIVE_NACK;
	}

Miss out on that return value or accidentally call to a module/output not on the bus and it is nappytime … forever. That is, at least until you power cycle. I’ve been able to tweak that library file to keep the unit from locking up, but I’ve not figured out how to bring the i2c bus back to life in a way where it will function and not lock up on future calls. My ignorance of the AVR TWI implementation (and the all over the place documentation) have kept me from solving this.

EXPERIMENT 1

This helps bolster my theory. I am able to read values for a much longer period of time if I disable the metronome and trigger the i2c input sampling from an external clock source. The TT will still lock up, but it takes a lot longer and happens more randomly than the near-instantaneous freeze when using the TT’s internal metronome interrupt. See the example video below.

I’m triggering SCRIPT 1 from the clock out of the 0-coast and am sampling its rise/fall generator via TI.IN 1 and pushing that value to CV 1 .

I’ve monitored the TXi and it gets and responds to all of the requests for data up until the moment of the freeze.

tehn · 2017-01-01T16:11:39.568Z

i2c reads need to happen conditionally-- we need to be checking if the i2c write (just prior) succeeded. otherwise the system will lock. should be an easy first fix. but there are other things lurking that are clearly causing trouble.

bpcmusic · 2017-01-02T01:52:08.448Z

So great to see you are having progress with this. I made a “yip” when I saw the notification email.

Quick question: I’d played around with (and reconfirmed) that if I comment out the the tele_ii_tx_now just before the read, it will still lock up immediately during the metro event and eventually during a triggered script. Is this the write you are referring to?

Thanks!

b

scanner_darkly · 2017-01-04T04:48:41.001Z

been looking into this, got a picoscope recently and remembered it does i2c decoding so thought i’d try that. confirmed first it decodes properly with orca remotes. then tried reading CV from ansible. no freezing when triggering manually (red is SDA, blue is SCL):

graph1.jpg719×328 150 KB

^ this is the last part, the 2nd byte in the ansible response to a write request which is not shown here. it returns data properly (in this case 0F). then i tried triggering it repeatedly by using WIN+1 to trigger a script and holding the buttons so it would keep calling it, and in a few seconds it froze. the read request from TT looks fine, as does the first byte sent by ansible but on the 2nd byte here is what happens:

graph2.jpg722×328 155 KB

looks like in the first graph it properly lets SDA go high after SCL is high to signal the end of transmission but in the 2nd one something pulls SDA back down and it stays down.

i’ll try more scenarios tomorrow - let me know if you want me to check anything specifically, thought i’d post this first in case it proves helpful. i’ve been reading up on i2c and looking at the code over the holidays and so far it does seem to be some sort of race condition… but that’s just a SWAG at this point.

ngwese · 2017-01-04T04:57:52.570Z

I started to experiment with trying to use a bus pirate board to snoop the i2c bus last night but don’t yet understand how to use the bus pirate properly so it hasn’t yields valuable results yet. If there is anyone out there with bus pirate experience I’m all ears.

…I’ve started work on sketching out some new ansible arp ideas (configurable via tt) so I expect to be pounding on the ii code during testing. Hopefully another set of eyes on all things ii will be a positive. Now off to further familiarize myself with the code and the spec.

tehn · 2017-01-04T14:00:04.861Z

good data points. i’m on this also this week, but i must admit the issues are not straightforward so any extra opinions and investigation are most welcome

fyi, SDA/SCL pullups:

ansible : 0
trilogy: 0
tt: 10k

scanner_darkly · 2017-01-04T19:07:41.548Z

also just noticed looking at the graphs there is no ACK from TT, not sure it’s related to the issues we’re seeing though, and don’t remember if it ACK'd the first byte or not - should’ve posted the full sequence, will do that once i get home.

scanner_darkly · 2017-01-05T04:43:55.242Z

sorry, just an info dump at this point, going through the code and cross referencing it with the graphs.

CV 5 16383
seems fine, can’t figure out why the address is 20 when judging by the code it should be II_ANSIBLE_ADDR 0xA0

image.png1459×815 17.1 KB

CV 5
also seems fine. TT sends II_ANSIBLE_CV | II_GET, then requests a read, and ansible sends 2 bytes. the only weirdness i see is a delay between the 2 bytes sent by ansible and TT not ACKing the 2nd byte:

image.png1567×757 16.8 KB

image.png693×723 8.36 KB

image.png690×720 8.84 KB

CV 6 CV 5
the start is similar to the above, TT sends a request to read CV, ansible returns 2 bytes.

image.png1178×729 15.3 KB

image.png690×723 8.76 KB

image.png771×736 9.83 KB

now the interesting part is that after TT receives the 2nd byte (same as doing CV 5) it starts a new transmission to set CV 6, but see how the 1st data package after the address package is stretched and it doesn’t transmit the clock for a while (either that or perhaps it’s ansible stretching the clock):

image.png738×730 11.2 KB

image.png702×731 10.2 KB

the behaviour with clock stretching seems pretty consistent.

scanner_darkly · 2017-01-05T05:16:07.188Z

one more observation: when trying L 5 8 : TR.PULSE I TT does send 4 transmissions. the first seems fine but in the last 3 i’m seeing similar clock stretching. interestingly enough L 5 8 : TR I 1 works (the outputs get set) even though i’m seeing same clock stretching, so might not be a factor in itself. and then if i try TR.PULSE after that outputs 1 and 3 pulse and 2 and 4 stay on.

tehn · 2017-01-05T16:42:29.520Z

@ngwese added your patch

pretty reliable read/writes by commenting out lines 95-102 in ansible_tt.c (on the ansible)

void ii_tt(uint8_t *d, uint8_t l) {
	// print_dbg("\r\ni2c:");
	// print_dbg_ulong(l);
	// print_dbg(" ");
	// for(int i=0;i<l;i++) {
	// 	print_dbg_ulong(d[i]);
	// 	print_dbg(" ");
	// }

but, i’m still seeing NACK on all the read requests also (with the analyzer). this is perplexing. i want to trust the ASF, but it’s worrying me.

but, it’s working, with the NACK and everything. but does not feel good.

i can still eventually overwhelm the event queue, but it takes a ton of at-once commands in succession.

hope to have more to report later.

ngwese · 2017-01-05T17:05:59.538Z

@tehn i’m assuming this is the patch you are talking about. i think a bunch of it is not needed so i’ll generate another more minimal PR instead.

i haven’t run into any problems yet writing from tt -> ansible during development. …going to implement a few more commands today which require more invasive changes then take things out for a test drive and try to break it.

tehn:

i want to trust the ASF, but it’s worrying me.

…i had that same feeling while trying to figure out why the usb stack was locking up back a month or so ago…

bpcmusic · 2017-01-05T18:04:01.774Z

Are the reads working on the TT’s Metro event for you with this change in the Ansible?

scanner_darkly · 2017-01-05T18:59:51.706Z

looking at the ASF code it appears NACK on reads is intentional to stop the slave from transmitting any more. which seems to go against i2c protocol but makes sense from a practical point of view (apologies if my interpretation is naive, i have a very limited knowledge of i2c).

  twi_masterBufferIndex = 0;
  twi_masterBufferLength = length-1;  // This is not intuitive, read on...
  // On receive, the previously configured ACK/NACK setting is transmitted in
  // response to the received byte before the interrupt is signalled. 
  // Therefor we must actually set NACK when the _next_ to last byte is
  // received, causing that NACK to be sent in response to receiving the last
  // expected byte of data.

scanner_darkly · 2017-01-05T19:23:47.034Z

i’m able to fix L 5 8 : TR.PULSE I by using multiple read buffers:

#define I2C_RX_BUF_COUNT 4
uint8_t rx_buffer_index = 0;

uint8_t rx_buffer[I2C_RX_BUF_COUNT][I2C_RX_BUF_SIZE];
static uint8_t rx_pos[I2C_RX_BUF_COUNT];

void twi_slave_rx( U8 u8_value )
{
  if (rx_pos[rx_buffer_index] < I2C_RX_BUF_SIZE) {
    rx_buffer[rx_buffer_index][rx_pos[rx_buffer_index]] = u8_value;
    rx_pos[rx_buffer_index]++;
  }
}

void twi_slave_stop( void )
{
  uint8_t counter = rx_buffer_index;
  if (++rx_buffer_index >= I2C_RX_BUF_COUNT) rx_buffer_index = 0;
  
  process_ii(rx_buffer[counter], rx_pos[counter]);
  rx_pos[counter] = 0;

this proves skipped commands are likely due to the fact that the buffer is overwritten while process_ii is executing. the solution can either be the above or having process_ii make a copy of the buffer data before it starts processing.

still getting freezing with CV 6 CV 5 in M script…

one more thing in the code above - added a check for rx_pos not to go over I2C_RX_BUF_SIZE

tehn · 2017-01-05T20:31:54.626Z

bpcmusic:

Are the reads working on the TT’s Metro event for you with this change in the Ansible?

i haven’t gotten to that yet.

but as another data point, i can’t get non-metro command to lock up with a non-existent i2c address, ie calling II WW.POS 2 without a WW attached.

@bpcmusic it’d be crazy helpful if you could scope/analyze your extender to see if you get an ACK after a TT read request.