I'm working on wireless upload to Arduino and i've succeed for Mega2560. But when trying to upload to Uno it does not wait for upload commands. I'm doing reset using GPIO and HM-10 BLE module wired with capacitor and resistor and wired to MCU's reset pin just it's done for USB. I think it remembers somehow how it was reset - by pressing hardware RESET button, by USB DTR/RTS or other way. The problem is that when resetting for USB it waits for upload commands after reset and for BLE it does not.
I've viewed optiboot bootloader code but i'm not sure i understand it correctly. Any clue on how to do it?
Update1:
2015-09-05 15:51:36.682 xctest[60180:7754033] [TRACE ] [OUT]: Send: A [0x41] T [0x54] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] 1 [0x31]
2015-09-05 15:51:36.682 xctest[60180:7754033] [TRACE ] [OUT]: BLE sending bytes range from 0 length 8
2015-09-05 15:51:36.735 xctest[60180:7754033] [DEBUG ] [OUT]: Sending 8 bytes
2015-09-05 15:51:36.736 xctest[60180:7754033] [TRACE ] [OUT]: Send: A [0x41] T [0x54] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] 0 [0x30]
2015-09-05 15:51:36.736 xctest[60180:7754033] [TRACE ] [OUT]: BLE sending bytes range from 0 length 8
2015-09-05 15:51:36.788 xctest[60180:7754033] [DEBUG ] [ ]: Draining for 300 ms ...
2015-09-05 15:51:36.788 xctest[60180:7754033] [TRACE ] [IN ]: Start reading
2015-09-05 15:51:37.053 xctest[60180:7754082] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 1 [0x31]
2015-09-05 15:51:37.053 xctest[60180:7754082] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 0 [0x30]
2015-09-05 15:51:37.093 xctest[60180:7754033] [TRACE ] [IN ]: Finish reading
2015-09-05 15:51:37.093 xctest[60180:7754033] [TRACE ] [IN ]: Ble clear buffer
2015-09-05 15:51:37.093 xctest[60180:7754033] [DEBUG ] [IN ]: Drained 18 bytes
2015-09-05 15:51:37.094 xctest[60180:7754033] [DEBUG ] [OUT]: Sending 2 bytes
2015-09-05 15:51:37.094 xctest[60180:7754033] [TRACE ] [OUT]: Send: 0 [0x30] [0x20]
2015-09-05 15:51:37.094 xctest[60180:7754033] [TRACE ] [OUT]: BLE sending bytes range from 0 length 2
2015-09-05 15:51:37.095 xctest[60180:7754033] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-05 15:51:37.096 xctest[60180:7754033] [TRACE ] [IN ]: Start reading
2015-09-05 15:51:37.450 xctest[60180:7754084] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-05 15:51:37.450 xctest[60180:7754084] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-05 15:51:37.450 xctest[60180:7754084] [TRACE ] [IN ]: Rx value received 2 bytes: . [0x14] . [0x10]
2015-09-05 15:51:37.452 xctest[60180:7754033] [TRACE ] [IN ]: Finish reading
2015-09-05 15:51:37.452 xctest[60180:7754033] [TRACE ] [IN ]: Receive: . [0x14]
2015-09-05 15:51:37.452 xctest[60180:7754033] [DEBUG ] [IN ]: Read 1 bytes, actually received 2 bytes
2015-09-05 15:51:37.453 xctest[60180:7754033] [TRACE ] [IN ]: 1 bytes in incoming buffer remaining for next receive
2015-09-05 15:51:37.453 xctest[60180:7754033] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-05 15:51:37.454 xctest[60180:7754033] [TRACE ] [IN ]: Having current receive buffer: . [0x10]
2015-09-05 15:51:37.454 xctest[60180:7754033] [TRACE ] [IN ]: Start reading
2015-09-05 15:51:37.454 xctest[60180:7754033] [TRACE ] [IN ]: Finish reading
2015-09-05 15:51:37.455 xctest[60180:7754033] [TRACE ] [IN ]: Receive: . [0x10]
2015-09-05 15:51:37.455 xctest[60180:7754033] [DEBUG ] [IN ]: Read 1 bytes, actually received 1 bytes
2015-09-05 15:51:37.455 xctest[60180:7754033] [TRACE ] [IN ]: Ble clear buffer
2015-09-05 15:51:37.455 xctest[60180:7754033] [DEBUG ] [OUT]: Sending 3 bytes
2015-09-05 15:51:37.456 xctest[60180:7754033] [TRACE ] [OUT]: Send: A [0x41] . [0x81] [0x20]
2015-09-05 15:51:37.456 xctest[60180:7754033] [TRACE ] [OUT]: BLE sending bytes range from 0 length 3
2015-09-05 15:51:37.457 xctest[60180:7754033] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-05 15:51:37.457 xctest[60180:7754033] [TRACE ] [IN ]: Start reading
2015-09-05 15:51:37.701 xctest[60180:7754084] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-05 15:51:37.701 xctest[60180:7754084] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-05 15:51:38.451 xctest[60180:7754082] [TRACE ] [IN ]: Rx value received 5 bytes: h [0x68] e [0x65] l [0x6C] l [0x6C] o [0x6F]
2015-09-05 15:51:38.452 xctest[60180:7754033] [TRACE ] [IN ]: Finish reading
Update 2 (this is uploading to Uno over USB log):
2015-06-29 16:34:10.829 xctest[36585:3703900] [TRACE ] [ ]: DTR/RTS supported by Serial, resetting
2015-06-29 16:34:11.140 xctest[36585:3703900] [DEBUG ] [IN ]: Draining ...
2015-06-29 16:34:11.392 xctest[36585:3703900] [DEBUG ] [IN ]: Drain done
2015-06-29 16:34:11.392 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 2 bytes
2015-06-29 16:34:11.392 xctest[36585:3703900] [TRACE ] [OUT]: Send: 0 [0x30] [0x20]
2015-06-29 16:34:11.393 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.531 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.531 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.532 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.532 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 3 bytes
2015-06-29 16:34:11.532 xctest[36585:3703900] [TRACE ] [OUT]: Send: A [0x41] . [0x81] [0x20]
2015-06-29 16:34:11.533 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.535 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.536 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.536 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x04]
2015-06-29 16:34:11.536 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.536 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.537 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 3 bytes
2015-06-29 16:34:11.537 xctest[36585:3703900] [TRACE ] [OUT]: Send: A [0x41] . [0x82] [0x20]
2015-06-29 16:34:11.537 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.540 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.540 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.540 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x04]
2015-06-29 16:34:11.540 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.541 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.541 xctest[36585:3703900] [DEBUG ] [ ]: STK500:initialize: n_extparms = 4
2015-06-29 16:34:11.541 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 22 bytes
2015-06-29 16:34:11.542 xctest[36585:3703900] [TRACE ] [OUT]: Send: B [0x42] . [0x86] . [0x00] . [0x01] . [0x00] . [0x01] . [0x01] . [0x01] . [0x03] . [0xFF] . [0xFF] . [0xFF] . [0xFF] . [0x00] . [0x80] . [0x04] . [0x00] . [0x00] . [0x00] . [0x80] . [0x00] [0x20]
2015-06-29 16:34:11.542 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.548 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.548 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.548 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.548 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 7 bytes
2015-06-29 16:34:11.549 xctest[36585:3703900] [TRACE ] [OUT]: Send: E [0x45] . [0x05] . [0x04] . [0xD7] . [0xC2] . [0x00] [0x20]
2015-06-29 16:34:11.549 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.552 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.552 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.552 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.553 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 2 bytes
2015-06-29 16:34:11.553 xctest[36585:3703900] [TRACE ] [OUT]: Send: P [0x50] [0x20]
2015-06-29 16:34:11.553 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.556 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14]
2015-06-29 16:34:11.556 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 1 bytes
2015-06-29 16:34:11.556 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x10]
2015-06-29 16:34:11.569 xctest[36585:3703900] Reading | | 0% 0ms
2015-06-29 16:34:11.570 xctest[36585:3703900] [DEBUG ] [OUT]: Sending 2 bytes
2015-06-29 16:34:11.571 xctest[36585:3703900] [TRACE ] [OUT]: Send: u [0x75] [0x20]
2015-06-29 16:34:11.571 xctest[36585:3703900] [DEBUG ] [IN ]: Receiving 5 bytes
2015-06-29 16:34:11.572 xctest[36585:3703900] [TRACE ] [IN ]: Received: . [0x14] . [0x1E] . [0x95] . [0x0F] . [0x10]
2015-06-29 16:34:11.572 xctest[36585:3703900] Reading | ################################################## | 100% 2ms
Update 3:
i've modified bootloader (optiboot) to wait 4 seconds (instead of 1 second by default) and added blinking when character 0x41 (STK_GET_PARAMETER) arrives. Also i've uploaded 'echo' sketch to return what back everything that is sent to the board.
bootloader modifications (part):
// Set up watchdog to trigger after 4s
watchdogConfig(WATCHDOG_4S); // 4ntoine: was WATCHDOG_1s
/* Set LED pin as output */
LED_DDR |= _BV(LED);
#ifdef SOFT_UART
/* Set TX pin as output */
UART_DDR |= _BV(UART_TX_BIT);
#endif
// #if LED_START_FLASHES > 0
/* Flash onboard LED to signal entering of bootloader */
// flash_led(2); // 4ntoine
// #endif
/* Forever loop */
for (;;) {
/* get character from UART */
ch = getch();
if(ch == STK_GET_PARAMETER) {
flash_led(2); // 4ntoine
unsigned char which = getch();
verifySpace();
if (which == 0x82) {
/*
* Send optiboot version as "minor SW version"
*/
putch(OPTIBOOT_MINVER);
} else if (which == 0x81) {
putch(OPTIBOOT_MAJVER);
} else {
/*
* GET PARAMETER returns a generic 0x03 reply for
* other parameters - enough to keep Avrdude happy
*/
putch(0x03);
}
}
uploaded arduino sketch:
int LED = 13;
void setup() {
// avoid misleading blinking
pinMode(LED, OUTPUT);
digitalWrite(LED, LOW);
// to let us know when sketch starts
Serial.begin(115200);
Serial.write("hello");
}
void loop() {
while (Serial.available()) {
int incomingByte = Serial.read();
Serial.write(incomingByte);
}
}
log:
2015-09-13 20:52:57.011 xctest[55099:2968978] [INFO ] [ ]: Found peripheral: <CBPeripheral: 0x100400af0 identifier = D92ECAAB-51A5-44D5-8C6C-536CD797867E, Name = "BleIos", state = disconnected>
2015-09-13 20:52:57.011 xctest[55099:2968978] [DEBUG ] [ ]: Stop scanning
2015-09-13 20:52:57.012 xctest[55099:2968978] [INFO ] [ ]: Connecting to <CBPeripheral: 0x100400af0 identifier = D92ECAAB-51A5-44D5-8C6C-536CD797867E, Name = "BleIos", state = disconnected>
2015-09-13 20:52:57.236 xctest[55099:2968989] [DEBUG ] [ ]: Connected to peripheral <CBPeripheral: 0x100400af0 identifier = D92ECAAB-51A5-44D5-8C6C-536CD797867E, Name = "BleIos", state = connected>
2015-09-13 20:52:57.238 xctest[55099:2968989] [TRACE ] [ ]: Discovered services for peripheral <CBPeripheral: 0x100400af0 identifier = D92ECAAB-51A5-44D5-8C6C-536CD797867E, Name = "BleIos", state = connected>
2015-09-13 20:52:57.238 xctest[55099:2968989] [DEBUG ] [ ]: Discovered service <CBService: 0x10010d950>
2015-09-13 20:52:57.381 xctest[55099:2968989] [TRACE ] [ ]: Discovered characteristics for service <CBService: 0x10010d950>
2015-09-13 20:52:57.381 xctest[55099:2968989] [TRACE ] [ ]: Discovered characteristic <CBCharacteristic: 0x100304d10>
2015-09-13 20:52:57.382 xctest[55099:2968989] [DEBUG ] [ ]: Tx characteristic supports WriteWithResponse: NO
2015-09-13 20:52:57.382 xctest[55099:2968989] [TRACE ] [ ]: Subscribing to Rx value
2015-09-13 20:52:57.392 xctest[55099:2968940] [INFO ] [ ]: Connected successfully
2015-09-13 20:52:57.392 xctest[55099:2968940] [TRACE ] [ ]: DTR/RTS supported by Serial, resetting
2015-09-13 20:52:57.392 xctest[55099:2968940] [TRACE ] [ ]: Waiting until subscribed to Rx value ...
2015-09-13 20:52:58.387 xctest[55099:2968989] [DEBUG ] [IN ]: Updated notifications state for RX characteristic: isNotifying=YES
2015-09-13 20:52:58.408 xctest[55099:2968940] [DEBUG ] [OUT]: Sending 8 bytes
2015-09-13 20:52:58.408 xctest[55099:2968940] [TRACE ] [OUT]: Send: A [0x41] T [0x54] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] 1 [0x31]
2015-09-13 20:52:58.408 xctest[55099:2968940] [TRACE ] [OUT]: BLE sending bytes range from 0 length 8
2015-09-13 20:52:58.463 xctest[55099:2968940] [DEBUG ] [OUT]: Sending 8 bytes
2015-09-13 20:52:58.463 xctest[55099:2968940] [TRACE ] [OUT]: Send: A [0x41] T [0x54] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] 0 [0x30]
2015-09-13 20:52:58.463 xctest[55099:2968940] [TRACE ] [OUT]: BLE sending bytes range from 0 length 8
2015-09-13 20:52:58.518 xctest[55099:2968940] [DEBUG ] [ ]: Draining for 300 ms ...
2015-09-13 20:52:58.518 xctest[55099:2968940] [TRACE ] [IN ]: Start reading
2015-09-13 20:52:58.784 xctest[55099:2968989] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 1 [0x31]
2015-09-13 20:52:58.785 xctest[55099:2968989] [WARNING] [IN ]: Removing 'OK+PIO2:1' (9 bytes) from incoming buffer (9 bytes)
2015-09-13 20:52:58.785 xctest[55099:2968989] [WARNING] [IN ]: Got 0 bytes in incoming buffer
2015-09-13 20:52:58.786 xctest[55099:2968989] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 0 [0x30]
2015-09-13 20:52:58.786 xctest[55099:2968989] [WARNING] [IN ]: Removing 'OK+PIO2:0' (9 bytes) from incoming buffer (9 bytes)
2015-09-13 20:52:58.787 xctest[55099:2968989] [WARNING] [IN ]: Got 0 bytes in incoming buffer
2015-09-13 20:52:58.820 xctest[55099:2968940] [TRACE ] [IN ]: Finish reading
2015-09-13 20:52:58.820 xctest[55099:2968940] [TRACE ] [IN ]: Ble clear buffer
2015-09-13 20:52:58.821 xctest[55099:2968940] [DEBUG ] [IN ]: Drained 0 bytes
2015-09-13 20:52:58.821 xctest[55099:2968940] [DEBUG ] [OUT]: Sending 2 bytes
2015-09-13 20:52:58.821 xctest[55099:2968940] [TRACE ] [OUT]: Send: 0 [0x30] [0x20]
2015-09-13 20:52:58.821 xctest[55099:2968940] [TRACE ] [OUT]: BLE sending bytes range from 0 length 2
2015-09-13 20:52:58.822 xctest[55099:2968940] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-13 20:52:58.822 xctest[55099:2968940] [TRACE ] [IN ]: Start reading
2015-09-13 20:52:59.193 xctest[55099:2968978] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-13 20:52:59.193 xctest[55099:2968978] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-13 20:52:59.193 xctest[55099:2968978] [TRACE ] [IN ]: Rx value received 2 bytes: . [0x14] . [0x10]
2015-09-13 20:52:59.194 xctest[55099:2968978] [WARNING] [IN ]: Got 2 bytes in incoming buffer
2015-09-13 20:52:59.194 xctest[55099:2968940] [TRACE ] [IN ]: Finish reading
2015-09-13 20:52:59.195 xctest[55099:2968940] [TRACE ] [IN ]: Receive: . [0x14]
2015-09-13 20:52:59.195 xctest[55099:2968940] [DEBUG ] [IN ]: Read 1 bytes, actually received 2 bytes
2015-09-13 20:52:59.195 xctest[55099:2968940] [TRACE ] [IN ]: 1 bytes in incoming buffer remaining for next receive
2015-09-13 20:52:59.196 xctest[55099:2968940] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-13 20:52:59.196 xctest[55099:2968940] [TRACE ] [IN ]: Having current receive buffer: . [0x10]
2015-09-13 20:52:59.196 xctest[55099:2968940] [TRACE ] [IN ]: Start reading
2015-09-13 20:52:59.196 xctest[55099:2968940] [TRACE ] [IN ]: Finish reading
2015-09-13 20:52:59.197 xctest[55099:2968940] [TRACE ] [IN ]: Receive: . [0x10]
2015-09-13 20:52:59.197 xctest[55099:2968940] [DEBUG ] [IN ]: Read 1 bytes, actually received 1 bytes
2015-09-13 20:52:59.197 xctest[55099:2968940] [TRACE ] [IN ]: Ble clear buffer
2015-09-13 20:52:59.198 xctest[55099:2968940] [DEBUG ] [OUT]: Sending 3 bytes
2015-09-13 20:52:59.198 xctest[55099:2968940] [TRACE ] [OUT]: Send: A [0x41] . [0x81] [0x20]
2015-09-13 20:52:59.198 xctest[55099:2968940] [TRACE ] [OUT]: BLE sending bytes range from 0 length 3
2015-09-13 20:52:59.199 xctest[55099:2968940] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-13 20:52:59.199 xctest[55099:2968940] [TRACE ] [IN ]: Start reading
2015-09-13 20:52:59.268 xctest[55099:2968978] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-13 20:52:59.268 xctest[55099:2968978] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-13 20:53:02.955 xctest[55099:2968940] [ERROR ] [OUT]: BLE read timeout: 3.000965 (timeout = 3.000000)
2015-09-13 20:53:02.955 xctest[55099:2968940] [TRACE ] [IN ]: Finish reading
2015-09-13 20:53:02.955 xctest[55099:2968940] [TRACE ] [IN ]: Ble clear buffer
2015-09-13 20:53:02.955 xctest[55099:2968940] [ERROR ] [IN ]: STK500:receive: programmer is not responding
2015-09-13 20:53:02.956 xctest[55099:2968940] [DEBUG ] [OUT]: Sending 3 bytes
2015-09-13 20:53:02.956 xctest[55099:2968940] [TRACE ] [OUT]: Send: A [0x41] . [0x82] [0x20]
2015-09-13 20:53:02.956 xctest[55099:2968940] [TRACE ] [OUT]: BLE sending bytes range from 0 length 3
2015-09-13 20:53:02.956 xctest[55099:2968940] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-13 20:53:02.957 xctest[55099:2968940] [TRACE ] [IN ]: Start reading
2015-09-13 20:53:03.018 xctest[55099:2968978] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-13 20:53:03.018 xctest[55099:2968978] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-13 20:53:03.280 xctest[55099:2968989] [TRACE ] [IN ]: Rx value received 5 bytes: h [0x68] e [0x65] l [0x6C] l [0x6C] o [0x6F]
2015-09-13 20:53:03.280 xctest[55099:2968989] [WARNING] [IN ]: Got 5 bytes in incoming buffer
2015-09-13 20:53:03.281 xctest[55099:2968940] [TRACE ] [IN ]: Finish reading
i can see blinking so the character arrives so the characters arrive correctly to the board. also i've tested wiring (sketch returns exactly the same as it was sent and it sends 'hello' after start). So i'm pretty sure: 1. characters arrive correctly to the bootloader 2. wiring is correct (as i can see back what i've sent - i'm using LightBlue mac app to open HM-10 as BLE device, subscribe to the characteristics and send characters and i can see it's changing to what i've sent). 3. bootloader waits for 4 seconds (i can see it in Arduino IDE terminal).
Update 4 :
my understanding now is that optiboot sets wrong baud rate for 115200 passed in bootloader mode as it replies with 0x11 and transmits characters correctly in sketch mode:
2015-09-17 09:39:25.628 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 1 [0x31]
2015-09-17 09:39:25.628 xctest[60179:4253160] [WARNING] [IN ]: Got 9 bytes in incoming buffer
2015-09-17 09:39:25.629 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 9 bytes: O [0x4F] K [0x4B] + [0x2B] P [0x50] I [0x49] O [0x4F] 2 [0x32] : [0x3A] 0 [0x30]
2015-09-17 09:39:25.629 xctest[60179:4253160] [WARNING] [IN ]: Got 9 bytes in incoming buffer
2015-09-17 09:39:25.630 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:25.630 xctest[60179:4253160] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-17 09:39:27.351 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:27.351 xctest[60179:4253117] [TRACE ] [IN ]: Ble clear buffer
2015-09-17 09:39:27.351 xctest[60179:4253117] [DEBUG ] [IN ]: Drained 18 bytes
2015-09-17 09:39:27.352 xctest[60179:4253117] [DEBUG ] [ ]: Draining incoming buffer (0 bytes)
2015-09-17 09:39:27.352 xctest[60179:4253117] [DEBUG ] [OUT]: Sending 2 bytes
2015-09-17 09:39:27.352 xctest[60179:4253117] [TRACE ] [OUT]: Send: 0 [0x30] [0x20]
2015-09-17 09:39:27.353 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 0 length 2
2015-09-17 09:39:27.353 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:27.353 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:27.424 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:27.424 xctest[60179:4253160] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-17 09:39:27.424 xctest[60179:4253149] [TRACE ] [IN ]: Rx value received 2 bytes: . [0x11] . [0xFC]
2015-09-17 09:39:27.425 xctest[60179:4253149] [WARNING] [IN ]: Got 2 bytes in incoming buffer
2015-09-17 09:39:27.425 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:27.425 xctest[60179:4253117] [TRACE ] [IN ]: Receive: . [0x11]
2015-09-17 09:39:27.425 xctest[60179:4253117] [DEBUG ] [IN ]: Read 1 bytes, actually received 2 bytes
2015-09-17 09:39:27.426 xctest[60179:4253117] [TRACE ] [IN ]: 1 bytes in incoming buffer remaining for next receive
2015-09-17 09:39:27.426 xctest[60179:4253117] [ERROR ] [ ]: STK500:synchronize: attempt 1 of 3: no sync: received [0x11]
2015-09-17 09:39:27.426 xctest[60179:4253117] [DEBUG ] [ ]: Draining incoming buffer (1 bytes)
2015-09-17 09:39:27.426 xctest[60179:4253117] [DEBUG ] [OUT]: Sending 2 bytes
2015-09-17 09:39:27.427 xctest[60179:4253117] [TRACE ] [OUT]: Send: 0 [0x30] [0x20]
2015-09-17 09:39:27.427 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 0 length 2
2015-09-17 09:39:27.427 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:27.427 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:27.499 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:27.499 xctest[60179:4253160] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-17 09:39:27.500 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 2 bytes: . [0x14] . [0x10]
2015-09-17 09:39:27.500 xctest[60179:4253160] [WARNING] [IN ]: Got 2 bytes in incoming buffer
2015-09-17 09:39:27.500 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:27.501 xctest[60179:4253117] [TRACE ] [IN ]: Receive: . [0x14]
2015-09-17 09:39:27.501 xctest[60179:4253117] [DEBUG ] [IN ]: Read 1 bytes, actually received 2 bytes
2015-09-17 09:39:27.501 xctest[60179:4253117] [TRACE ] [IN ]: 1 bytes in incoming buffer remaining for next receive
2015-09-17 09:39:27.501 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:27.501 xctest[60179:4253117] [TRACE ] [IN ]: Having current receive buffer: . [0x10]
2015-09-17 09:39:27.502 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:27.502 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:27.502 xctest[60179:4253117] [TRACE ] [IN ]: Receive: . [0x10]
2015-09-17 09:39:27.508 xctest[60179:4253117] [DEBUG ] [IN ]: Read 1 bytes, actually received 1 bytes
2015-09-17 09:39:27.509 xctest[60179:4253117] [TRACE ] [IN ]: Ble clear buffer
2015-09-17 09:39:27.509 xctest[60179:4253117] [DEBUG ] [OUT]: Sending 3 bytes
2015-09-17 09:39:27.509 xctest[60179:4253117] [TRACE ] [OUT]: Send: A [0x41] . [0x81] [0x20]
2015-09-17 09:39:27.509 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 0 length 3
2015-09-17 09:39:27.510 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:27.510 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:27.574 xctest[60179:4253149] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:27.574 xctest[60179:4253149] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-17 09:39:31.325 xctest[60179:4253117] [ERROR ] [OUT]: BLE read timeout: 3.000965 (timeout = 3.000000)
2015-09-17 09:39:31.326 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:31.326 xctest[60179:4253117] [TRACE ] [IN ]: Ble clear buffer
2015-09-17 09:39:31.326 xctest[60179:4253117] [ERROR ] [IN ]: STK500:receive: programmer is not responding
2015-09-17 09:39:31.327 xctest[60179:4253117] [DEBUG ] [OUT]: Sending 3 bytes
2015-09-17 09:39:31.327 xctest[60179:4253117] [TRACE ] [OUT]: Send: A [0x41] . [0x82] [0x20]
2015-09-17 09:39:31.327 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 0 length 3
2015-09-17 09:39:31.328 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:31.328 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:31.399 xctest[60179:4253160] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:31.400 xctest[60179:4253160] [TRACE ] [IN ]: Ignoring single 0x00 char
2015-09-17 09:39:35.173 xctest[60179:4253117] [ERROR ] [OUT]: BLE read timeout: 3.000965 (timeout = 3.000000)
2015-09-17 09:39:35.173 xctest[60179:4253117] [TRACE ] [IN ]: Finish reading
2015-09-17 09:39:35.174 xctest[60179:4253117] [TRACE ] [IN ]: Ble clear buffer
2015-09-17 09:39:35.174 xctest[60179:4253117] [ERROR ] [IN ]: STK500:receive: programmer is not responding
2015-09-17 09:39:35.174 xctest[60179:4253117] [DEBUG ] [ ]: STK500:initialize: n_extparms = 3
2015-09-17 09:39:35.175 xctest[60179:4253117] [DEBUG ] [OUT]: Sending 22 bytes
2015-09-17 09:39:35.175 xctest[60179:4253117] [TRACE ] [OUT]: Send: B [0x42] . [0x86] . [0x00] . [0x01] . [0x00] . [0x01] . [0x01] . [0x01] . [0x03] . [0xFF] . [0xFF] . [0xFF] . [0xFF] . [0x00] . [0x80] . [0x04] . [0x00] . [0x00] . [0x00] . [0x80] . [0x00] [0x20]
2015-09-17 09:39:35.175 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 0 length 20
2015-09-17 09:39:35.176 xctest[60179:4253117] [TRACE ] [OUT]: BLE sending bytes range from 20 length 2
2015-09-17 09:39:35.177 xctest[60179:4253117] [DEBUG ] [IN ]: Reading 1 bytes ...
2015-09-17 09:39:35.177 xctest[60179:4253117] [TRACE ] [IN ]: Start reading
2015-09-17 09:39:35.224 xctest[60179:4253149] [TRACE ] [IN ]: Rx value received 1 bytes: . [0x00]
2015-09-17 09:39:35.224 xctest[60179:4253149] [TRACE ] [IN ]: Ignoring single 0x00 char
Should it work if i wire pins 0 and 1 at Uno to RX/TX (it does work for Mega2560)? Here is soft uart code from optiboot:
#ifndef SOFT_UART
#ifdef __AVR_ATmega8__
UCSRA = _BV(U2X); //Double speed mode USART
UCSRB = _BV(RXEN) | _BV(TXEN); // enable Rx & Tx
UCSRC = _BV(URSEL) | _BV(UCSZ1) | _BV(UCSZ0); // config USART; 8N1
UBRRL = (uint8_t)( (F_CPU + BAUD_RATE * 4L) / (BAUD_RATE * 8L) - 1 );
#else
UCSR0A = _BV(U2X0); //Double speed mode USART0
UCSR0B = _BV(RXEN0) | _BV(TXEN0);
UCSR0C = _BV(UCSZ00) | _BV(UCSZ01);
UBRR0L = (uint8_t)( (F_CPU + BAUD_RATE * 4L) / (BAUD_RATE * 8L) - 1 );
#endif
#endif
#ifdef SOFT_UART
/* Set TX pin as output */
UART_DDR |= _BV(UART_TX_BIT);
#endif
Should RX be set as input separately too (like Tx as output)? Why it tries to set 'Double speed'?