Bus Timeout, Documentation, Code Ordering

Add I2C_ERROR_BUS_BUSY, improve documentation, Setting the bus speed
below 10kHZ caused a Div0 error, Changed timeout calcuation to handle
extremely slow speeds. Reorderd coding to remove Compiler warnings
(@dstoiko)

cores/esp32/esp32-hal-i2c.c

@@ -636,9 +636,14 @@ static void IRAM_ATTR fillTxFifo(i2c_t * i2c){
 /*11/15/2017 will assume that I cannot queue tx after a READ until READ completes
 11/23/2017 Seems to be a TX fifo problem, the SM sends 0x40 for last rxbyte, I
 enable txEmpty, filltx fires, but the SM has already sent a bogus byte out the BUS.
-I am going so see if I can overlap Tx/Rx/Tx in the fifo
+  I am going so see if I can overlap Tx/Rx/Tx in the fifo
+12/01/2017 The Fifo's are independent, 32 bytes of tx and 32 bytes of Rx.
+   overlap is not an issue, just keep them full/empty the status_reg.xx_fifo_cnt
+   tells the truth. And the INT's fire correctly
 */
-bool readEncountered = false;  
+bool readEncountered = false;  // 12/01/2017 this needs to be removed
+// it is nolonger necessary, the fifo's are independent. Run thru the dq's
+// until the cmd[] is full or the txFifo is full.
 uint16_t a=i2c->queuePos; // currently executing dq,
 bool full=!(i2c->dev->status_reg.tx_fifo_cnt<31);
 uint8_t cnt;
@@ -795,11 +800,8 @@ if(xResult == pdPASS){
 }  
 
 static void IRAM_ATTR i2c_isr_handler_default(void* arg){
-//log_e("isr Entry=%p",arg);
 i2c_t* p_i2c = (i2c_t*) arg; // recover data
 uint32_t activeInt = p_i2c->dev->int_status.val&0x1FFF;
-//log_e("int=%x",activeInt);
-//dumpI2c(p_i2c);
 
 portBASE_TYPE HPTaskAwoken = pdFALSE,xResult; 
 
@@ -886,12 +888,11 @@ while (activeInt != 0) { // Ordering of 'if(activeInt)' statements is important,
     return;
     }
 
-  if (activeInt & I2C_TIME_OUT_INT_ST_M) {//fatal death Happens Here
- // let Gross timeout occure
+  if (activeInt & I2C_TIME_OUT_INT_ST_M) {
+ // let Gross timeout occur, Slave may release SCL before the configured timeout expires
+ // the Statemachine only has a 13.1ms max timout, some Devices >500ms
     p_i2c->dev->int_clr.time_out =1;
     activeInt &=~I2C_TIME_OUT_INT_ST;
-//    i2cIsrExit(p_i2c,EVENT_ERROR_TIMEOUT,true);
-//    return;
     } 
 
   if (activeInt & I2C_TRANS_COMPLETE_INT_ST_M) { 
@@ -973,7 +974,9 @@ i2c->stage = I2C_DONE; // until ready
 memset(intBuff,0,sizeof(intBuff));
 intPos=0;
 #endif
-
+// EventGroup is used to signal transmisison completion from ISR
+// not always reliable. Sometimes, the FreeRTOS scheduler is maxed out and refuses request
+// if that happens, this call hangs until the timeout period expires, then it continues.  
 if(!i2c->i2c_event){
   i2c->i2c_event = xEventGroupCreate();
   }
@@ -1046,7 +1049,7 @@ i2c->stage = I2C_STARTUP; // everything configured, now start the I2C StateMachi
 i2c->dev->int_ena.val = 
   I2C_ACK_ERR_INT_ENA | // (BIT(10))  Causes Fatal Error Exit
   I2C_TRANS_START_INT_ENA | // (BIT(9))  Triggered by trans_start=1, initial,END
-  I2C_TIME_OUT_INT_ENA  | //(BIT(8))  causes Fatal error Exit
+  I2C_TIME_OUT_INT_ENA  | //(BIT(8))  Trigger by SLAVE SCL stretching, NOT an ERROR
   I2C_TRANS_COMPLETE_INT_ENA | // (BIT(7))  triggered by STOP, successful exit
   I2C_MASTER_TRAN_COMP_INT_ENA | // (BIT(6))  counts each byte xfer'd, inc's queuePos
   I2C_ARBITRATION_LOST_INT_ENA | // (BIT(5))  cause fatal error exit
@@ -1071,7 +1074,7 @@ if(!i2c->intr_handle){ // create ISR I2C_0 only,
 // how many ticks should it take to transfer totalBytes thru the I2C hardware,
 // add user supplied timeOutMillis to Calc Value
 
-portTickType ticksTimeOut = ((totalBytes /(i2cGetFrequency(i2c)/(10*1000)))+timeOutMillis)/portTICK_PERIOD_MS;
+portTickType ticksTimeOut = ((totalBytes*10*1000)/(i2cGetFrequency(i2c))+timeOutMillis)/portTICK_PERIOD_MS;
 portTickType tBefore=xTaskGetTickCount();  
 
 //log_e("before startup @tick=%d will wait=%d",xTaskGetTickCount(),ticksTimeOut);
@@ -1094,11 +1097,24 @@ if(i2c->exitCode!=eBits){ // try to recover from O/S failure
   }
 
 if(!(eBits==EVENT_DONE)&&(eBits&~(EVENT_ERROR_NAK|EVENT_ERROR_DATA_NAK|EVENT_ERROR|EVENT_DONE))){ // not only Done, therefore error, exclude ADDR NAK, DATA_NAK
+#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
   i2cDumpI2c(i2c);
   i2cDumpInts();
+#else
+  log_n("I2C exitCode=%u",eBits);
+#endif
   }
 
 if(eBits&EVENT_DONE){ // no gross timeout
+#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
+  uint32_t expected =(totalBytes*10*1000)/i2cGetFrequency(i2c);
+  if((tAfter-tBefore)>(expected+1)) { //used some of the timeout Period
+    // expected can be zero due to small packets
+    log_e("TimeoutRecovery: expected=%ums, actual=%ums",expected,(tAfter-tBefore));
+    i2cDumpI2c(i2c);
+    i2cDumpInts();
+    }
+#endif
   switch(i2c->error){
     case I2C_OK :
       reason = I2C_ERROR_OK;
@@ -1126,11 +1142,25 @@ else { // GROSS timeout, shutdown ISR , report Timeout
   i2c->stage = I2C_DONE;
   i2c->dev->int_ena.val =0;
   i2c->dev->int_clr.val = 0x1FFF;
-  reason = I2C_ERROR_TIMEOUT;
-  eBits = eBits | EVENT_ERROR_TIMEOUT|EVENT_ERROR|EVENT_DONE;
-  log_e(" Gross Timeout Dead st=0x%x, ed=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
+  if((i2c->queuePos==0)&&(i2c->byteCnt==0)){ // Bus Busy no bytes Moved
+    reason = I2C_ERROR_BUSY;
+    eBits = eBits | EVENT_ERROR_BUS_BUSY|EVENT_ERROR|EVENT_DONE;
+#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
+  log_e(" Busy Timeout start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
   i2cDumpI2c(i2c);
   i2cDumpInts();
+#endif
+    }
+  else { // just a timeout, some data made it out or in.
+    reason = I2C_ERROR_TIMEOUT;
+    eBits = eBits | EVENT_ERROR_TIMEOUT|EVENT_ERROR|EVENT_DONE;
+
+#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
+  log_e(" Gross Timeout Dead start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
+  i2cDumpI2c(i2c);
+  i2cDumpInts();
+#endif
+    }
   }
 
 // offloading all EventGroups to dispatch, EventGroups in ISR is not always successful

cores/esp32/esp32-hal-i2c.h

@@ -104,6 +104,7 @@ typedef enum {
 // on Exit.  Dispatcher will set bits for each dq before/after ISR completion
 #define EVENT_ERROR_NAK (BIT(0))
 #define EVENT_ERROR     (BIT(1))
+#define EVENT_ERROR_BUS_BUSY  (BIT(2))
 #define EVENT_RUNNING   (BIT(3)) 
 #define EVENT_DONE      (BIT(4))
 #define EVENT_IN_END    (BIT(5))

libraries/Wire/docs/README.md

@@ -14,8 +14,8 @@ Wire.write(highByte(addr));
 Wire.write(lowByte(addr));
 uint8_t err =Wire.endTransmission(false); // don't send a STOP, just Pause I2C operations
 if(err==0){ // successfully set internal address pointer
-  err=Wire.requestFrom(addr,len);
-  if(err==0){ // read failed
+  uint8_t count=Wire.requestFrom(addr,len);
+  if(count==0){ // read failed
     Serial.print("Bad Stuff!! Read Failed\n");
     }
   else {// successful read
@@ -59,10 +59,10 @@ if(err == 7){ // Prior Operation has been queued
 // returned 0. So, if this if() was if(err==0), the Queue operation would be
 // considered an error.  This is the primary Difference.
 
-  err=Wire.requestFrom(addr,len);
+  uint8_t count=Wire.requestFrom(addr,len);
   if(Wire.lastError()!=0){ // complete/partial read failure
     Serial.printf("Bad Stuff!!\nRead of (%d) bytes read %d bytes\nFailed"
-      " lastError=%d, text=%s\n", len, err, Wire.lastError(), 
+      " lastError=%d, text=%s\n", len, count, Wire.lastError(), 
       Wire.getErrorText(Wire.lastError()));
     }
   // some of the read may have executed
@@ -82,7 +82,11 @@ Additionally this implementation of `Wire()` includes methods to handle local bu
     size_t transact(size_t readLen); // replacement for endTransmission(false),requestFrom(ID,readLen,true);
     size_t transact(uint8_t* readBuff, size_t readLen);// bigger Block read
     i2c_err_t lastError(); // Expose complete error
+    char * getErrorText(uint8_t err); // return char pointer for text of err
+    void dumpI2C(); // diagnostic dump of I2C control structure and buffers
     void dumpInts(); // diagnostic dump for the last 64 different i2c Interrupts
+    void dumpOn(); // Execute dumpI2C() and dumpInts() after every I2C procQueue()
+    void dumpOff(); // turn off dumpOn()
     size_t getClock(); // current i2c Clock rate
     void setTimeOut(uint16_t timeOutMillis); // allows users to configure Gross Timeout
     uint16_t getTimeOut();
@@ -95,7 +99,7 @@ Wire.beginTransmission(ID);
 Wire.write(highByte(addr));
 Wire.write(lowByte(addr));
 
-uint8_t err=Wire.transact(len); // transact() does both Wire.endTransmission(false); and Wire.requestFrom(ID,len,true);
+uint8_t count=Wire.transact(len); // transact() does both Wire.endTransmission(false); and Wire.requestFrom(ID,len,true);
 if(Wire.lastError != 0){ // complete/partial read failure
   Serial.printf("Bad Stuff!! Read Failed lastError=%d\n",Wire.lastError());
   }
@@ -107,10 +111,20 @@ Serial.println();
 
 ```
 
+### TIMEOUT's
+The ESP32 I2C hardware, what I call the StateMachine(SM) is not documented very well, most of the the corner conditions and errata has been discovered throught trial and error. TimeOuts have been the bain of our existance. 
+
+Most were caused by incorrect coding of ReSTART operations, but, a Valid TimeOut operation was discovered by @lonerzzz.  He was using a temperature/humidity sensor that uses SCL clock stretching while it does a sample conversion.  The issue we discovered was that the SM does not continue after the timeout.  It treats the timeout as a failure.  The SM's hardware timeout maxes out at 13.1ms, @lonerzzz sensor a (HTU21D), uses SCL stretching while it takes a measurement.  These SCL stretching events can last for over 120ms.  The SM will issue a TIMEOUT IRQ every 13.1ms while SCL is held low.  After SCL is release the SM immediately terminates the current command queue by issuing a STOP.  It does NOT continue with the READ command(a protcol violation).  In @lonerzzz's case the sensor acknowledges its I2C ID and the READ command, then it starts the sample conversion while holding SCL Low.  After it completes the conversion, the SCL signal is release.  When the SM sees SCL go HIGH, it initates an Abort by immediately issuing a STOP signal.  So, the Sample was taken but never read.
+
+The current library signals this occurence by returning I2C_ERROR_OK and a dataLength of 0(zero) back through the `Wire.requestFrom()` call.
+
+### Alpha
+
 This **APLHA** release should be compiled with ESP32 Dev Module as its target, and
 Set the "core debug level" to 'error'
 
 There is MINIMAL to NO ERROR detection, BUS, BUSY.  because I have not encounter any of them!
 
 
 Chuck.
+

libraries/Wire/examples/eeprom_size/eeprom_size.ino

@@ -1,18 +1,38 @@
 #include <Wire.h>
 // Connect 4.7k pullups on SDA, SCL
 // for ESP32 SDA(pin 21), SCL(pin 22)
-// for AtMega328p SDA(Pin A5), SCL(pin A4)
-// for Mega2560 SDA(Pin 20), SCL(pin 21)
 
 /* This sketch uses the address rollover of the 24LCxx EEPROMS to detect their size.
-  The 24LC32 (4kByte) 0x0000 .. 0x0FFF, a Write to addres 0x1000 will actually
+  This detection sequence will not work with small capacity EEPROMs 24LC01 .. 24LC16.
+    These small EEPROMS use single byte addressing, To access more than 256 bytes,
+    the lc04, lc08, and lc16 EEPROMs respond as if they were multiple lc02's with
+    consective I2CDevice addresses.
+    device I2Caddr Address Range
+    24LC01 0x50     0x00 .. 0x7F
+    24LC02 0x50     0x00 .. 0xFF
+    24LC04 0x50     0x00 .. 0xFF
+           0x51     0x00 .. 0xFF
+    24LC08 0x50     0x00 .. 0xFF
+           0x51     0x00 .. 0xFF
+           0x52     0x00 .. 0xFF
+           0x53     0x00 .. 0xFF
+    24LC16 0x50     0x00 .. 0xFF
+           0x51     0x00 .. 0xFF
+           0x52     0x00 .. 0xFF
+           0x53     0x00 .. 0xFF
+           0x54     0x00 .. 0xFF
+           0x55     0x00 .. 0xFF
+           0x56     0x00 .. 0xFF
+           0x57     0x00 .. 0xFF
+  The 24LC32 with selectable I2C address 0x50..0x57 are 4kByte devices with an internal
+  address range of 0x0000 .. 0x0FFF. A Write to address 0x1000 will actually
   be stored in 0x0000.  This allows us to read the value of 0x0000, compare
   it to the value read from 0x1000, if they are different, then this IC is
   not a 24LC32.
   If the Value is the same, then we have to change the byte at 0x1000 and
   see if the change is reflected in 0x0000.  If 0x0000 changes, then we know
   that the chip is a 24LC32.  We have to restore the 'changed' value so that
-  the data in the EEPROM is not compromized.
+  the data in the EEPROM is not compromised.
 
   This pattern of read, compare, test, restore is used for each possible size.
   All that changes is the test Address, 0x1000, 0x2000, 0x4000, 0x8000.
@@ -27,7 +47,8 @@
 bool i2cReady(uint8_t ID){
 uint32_t timeout=millis();
 bool ready=false;
-while((millis()-timeout<100)&&(!ready)){
+while((millis()-timeout<10)&&(!ready)){ // try to evoke a response from the device.
+// If the it does not respond within 10ms return as a failure.
   Wire.beginTransmission(ID);
   int err=Wire.endTransmission();
   ready=(err==0);
@@ -38,6 +59,103 @@ while((millis()-timeout<100)&&(!ready)){
 return ready;
 }
 
+void dispBuff(uint8_t *buf, uint16_t len,uint16_t offset){
+char asciibuf[100];
+uint8_t bufPos=0;
+uint16_t adr=0;
+asciibuf[0] ='\0';
+while(adr<len){
+	if(((offset+adr)&0x1F)==0){
+    if(asciibuf[0]) Serial.printf(" %s\n",asciibuf);
+		Serial.printf("0x%04x:",(uint16_t)(offset+adr));
+		bufPos=0;
+		}
+	Serial.printf(" %02x",buf[adr]);
+	char ch=buf[adr];
+	if((ch<32)||(ch>127)) ch ='.';
+	bufPos+=sprintf(&asciibuf[bufPos],"%c",ch);
+	adr++;
+	}
+
+while(bufPos<32){
+	Serial.print("   ");
+	bufPos++;
+	}
+Serial.printf(" %s\n",asciibuf);
+}
+
+/* detectWritePageSize() attempts to write a 256 byte block to an I2C EEPROM.
+  This large block will use the side effect of the WritePage to detect it's size.
+  EEPROM's have to erase a 'page' of data in their memory cell array before they 
+  can change it. To facilitate partial page writes they contain a temporary 'WritePage'
+  that is used store the contents of the memory cells while their page is erase.
+  When data is written to the device it is merged into this temporary buffer.  If the 
+  amount of data written is longer than the temporary buffer it rolls over to the beginning
+  of the temporary buffer.  In a 24lc32, the standard WritePage is 32 bytes, if 256
+  bytes of data is written to the device, only the last 32 bytes are stored.
+  This side effect allow easy detect of the WritePage size.
+*/
+
+uint16_t detectWritePageSize(uint16_t i2cID,bool verbose=false){
+if(verbose) Serial.printf("detecting WritePage Size for (0x%02x)\n",i2cID);
+uint16_t adr = 0,ps=0;
+randomSeed(micros());
+adr = random(256)*256; //address is selected at random for wear leveling purposes.
+uint8_t *buf =(uint8_t*)malloc(256); //restore buffer
+uint8_t *buf1 =(uint8_t*)malloc(258); // write buffer
+i2cReady(i2cID); // device may completing a Write Cycle, wait if necessary
+Wire.beginTransmission(i2cID);
+Wire.write(highByte(adr));
+Wire.write(lowByte(adr));
+uint16_t count = Wire.transact(buf,256);//save current EEPROM content for Restore
+if(Wire.lastError()==0){ // successful read, now we can try the test
+  for(uint16_t a=0;a<256;a++){ //initialize a detectable pattern in the writeBuffer
+    buf1[a+2]=a;   // leave room for the the address 
+    }
+  buf1[0] = highByte(adr);
+  buf1[1] = lowByte(adr);
+  Wire.writeTransmission(i2cID,buf1,258);
+  if(Wire.lastError()==0){ // wait for the write to complete
+    if(i2cReady(i2cID)){
+      Wire.beginTransmission(i2cID);
+      Wire.write(highByte(adr));
+      Wire.write(lowByte(adr));
+      Wire.transact(&buf1[2],256);
+      if(Wire.lastError()==0){
+        ps = 256-buf1[2]; // if the read succeeded, the byte read from offset 0x0
+        // can be used to calculate the WritePage size.  On a 24lc32 with a 32byte
+        // WritePage it will contain 224, therefore 256-224 = 32 byte Writepage.
+        if(verbose){
+          Serial.printf("Origonal data\n",i2cID);
+          dispBuff(buf,256,adr);
+          Serial.printf("\n OverWritten with\n");
+          dispBuff(&buf1[2],256,adr);
+          Serial.printf("Calculated Write Page is %d\n",ps);
+          }
+        memmove(&buf1[2],buf,256); // copy the savebuffer back into
+        if(i2cReady(i2cID)){
+          Wire.writeTransmission(i2cID,buf1,ps+2); // two address bytes plus WritePage
+          }
+        if(Wire.lastError()!=0){
+          Serial.printf("unable to Restore prom\n");
+          if(i2cReady(i2cID)){
+            Wire.beginTransmission(i2cID);
+            Wire.write(highByte(adr));
+            Wire.write(lowByte(adr));
+            Wire.transact(&buf1[2],256);
+            Serial.printf("\n Restored to\n");
+            dispBuff(&buf1[2],256,adr);
+            }
+          }
+        }
+      }
+    }
+  }
+free(buf1);
+free(buf);
+return ps;
+}
+
 /* eepromSize() only works on 24LC32 .. 24LC512 eeprom,
  the smaller 24LC01 .. 24LC16 use one byte addressings.
 */
@@ -127,7 +245,8 @@ while(ID<0x58){
             }
           }while((testByte==zeroByte)&&(size>0));
         if(size==0) i += sprintf_P(&buf[i],PSTR("64k Bytes"));
-        else i+=sprintf_P(&buf[i],PSTR("%dk Bytes"),size/1024);
+        else i+=sprintf_P(&buf[i],PSTR("%2uk Bytes"),size/1024);
+        i+=sprintf_P(&buf[i],PSTR(" WritePage=%3u"),detectWritePageSize(ID,false));
         if(!i2cReady(ID)){
           i+=sprintf_P(&buf[i],PSTR(" notReady3.\n"));
           Serial.print(buf);
@@ -139,7 +258,7 @@ while(ID<0x58){
         Wire.write((uint8_t)0); // set address ptr to 0, two bytes Low
         err=Wire.endTransmission();
         if(err==0){
-          err= Wire.requestFrom(ID,1);
+          err= Wire.requestFrom(ID,(uint8_t)1);
           if (err==1) {
             testByte = Wire.read();
             if(testByte != zeroByte){ //fix it

libraries/Wire/src/Wire.cpp

@@ -39,12 +39,12 @@ TwoWire::TwoWire(uint8_t bus_num)
     ,i2c(NULL)
     ,rxIndex(0)
     ,rxLength(0)
+    ,rxQueued(0)
     ,txIndex(0)
     ,txLength(0)
     ,txAddress(0)
-    ,transmitting(0)
     ,txQueued(0)
-    ,rxQueued(0)
+    ,transmitting(0)
     ,_timeOutMillis(50)
     ,last_error(I2C_ERROR_OK)
     ,_dump(false)