search

vovagorodok / ArduinoBleOTA

Upload firmware over Bluetooth
MIT License
19 stars 7 forks source link

upload App says is wrote data, device counts don't match #26

Closed sdetweil closed 1 year ago

sdetweil commented 1 year ago

i am working thru porting upload to my app

firmware image is 658448 bytes sending 512 byte blocks, is 1287 sends

I added debugging on entrance/exit to onData and handleBegin and handlePackage device begin to end.. 80 times receiving data, 7 times says sending ok from handlePackage, 10 512/blocks between OK's

recevied data length=5
data=16
sending begin response
Begin upload, size=658448
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package ------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package ----------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package -------------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package --------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package -------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package --------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
sending ok for package ----------------------------
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage
recevied data length=512
data=17
received package
length=511
exiting handlePackage

the app loop for send is quite higher priority than the subscribe notice, so the oks flood in at the end...

app 

begin sequence
------
⚡️  [log] - starting transfer of 658448 bytes
⚡️  [log] - subscribe info={"status":"subscribed","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6","service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B"}
⚡️  [log] -  build begin data 
⚡️  [log] - begin data to be written=10100c0a00
⚡️  [log] - number = 0x10
⚡️  [log] - y=''
⚡️  [log] - len =1
⚡️  [log] - number = 0x10
⚡️  [log] - y=''
⚡️  [log] - len =2
⚡️  [log] - number = 0x0c
⚡️  [log] - y=''
⚡️  [log] - len =3
To Native Cordova ->  BluetoothLePlugin write ⚡️  [log] - number = 0x0a
BluetoothLePlugin620564788 ["options": [{
    address = "F2195DF1-3329-F489-6E77-E917B966BD9B";
    characteristic = "15c1564c-36c5-11ed-adc1-a3d6cf5cc2a4";
    service = "15c155ca-36c5-11ed-adc0-9741d6a72f04";
    type = noResponse;
    value = "EBAMCgA=";
}]]
⚡️  [log] - y='
'
⚡️  [log] - len =4
⚡️  [log] - number = 0x00
⚡️  [log] - y='⚡️  [log] - send begin write rc={"status":"written","value":"EBAMCgA=","characteristic":"15C1564C-36C5-11ED-ADC1-A3D6CF5CC2A4","name":"b0:a7:32:81:93:e6","service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B"}
⚡️  [log] - sendbegin waiting

⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AAACAAD2EwAA","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}
⚡️  [log] - in handle response
⚡️  [log] - resolving waitpromise

⚡️  [log] - data=[0,0,2,0,0,246,19,0,0]
⚡️  [log] - subscribe result data=0,0,2,0,0,246,19,0,0 array type=true
⚡️  [log] - in handleBegin
⚡️  [log] - getting sizes from device
⚡️  [log] - data length=9 offset=1
⚡️  [log] - data=0200
To Native Cordova ->  BluetoothLePlugin mtu BluetoothLePlugin620564789 ⚡️  [log] - data length=9 offset=5
["options": [{
    address = "F2195DF1-3329-F489-6E77-E917B966BD9B";
    mtu = 516;
}]]
⚡️  [log] - data=2461900
⚡️  [log] - mtu size=516
⚡️  [log] - mtu rc={}
⚡️  [log] - entering sendPackages
⚡️  [log] - sending package, start=0 end=511

--- last 512 block 

 [log] - length of data =512
⚡️  [log] - sendData write rc=**{"status":"written","value"**:"EcAgAIgEiBjAIADgCADcaqgCSAqCJBFWGAGtAjgSSBMyIxW4NOADAC0KHfBIEr0DyITgCAAWGv4G+/8ANoEASBIMCyCiIEi04AQAVjoGrQJIEogUQiQVuAjgBABWKgW9ChzMS6FIAiVC9iwIkX2YNzkBHIiCQQfAIACCoNw5ITc5AoKg2EuxrQSCUQzAIACIBIgYwCAA4AgA3FqoAkgKgiQR3AitAjgSSBMyIxW4JOADAC0KHfBIEr0DwiQJ4AgAFgr+xvr/AAA2QQAwIPUyoO8wIsAMCDKhBSA4gy0DHfA2QQAiAhgciQwIJ7kCgqACDEIgKCAd8AAgSAMbIgACQDBJAzAgkQAzodbzCzAw9TAiICAwYCAzEDDzQAATQCAgkSBJEyBIAyLCHzAywDBIExAgACBJAxaiBwfiCBfiGSfiOgYjADLJ8EkDWRNpI3kzIGFBEIBABvf/Ms3wSQNZE2kjeTMyxfQ4AzLD4IkDmROpI7kzIKJBIIBABu7/EIBA0s3wCQ0ZHSktOT0ywfQ4A9LNEDLD0EkDWRNpI3kziUOZU6ljuXPwgEAg40EwgEDG4P8AABCAQCBIAwASQAwSACKhIEkTECAADAIN8AwSDfAAAPAiERsiMEgD9+IKCzPwIhH3YvcwMDQAE0AAMhEwIoEgIPQgSRMwAwMsAjAywDA=","characteristic":"15C1564C-36C5-11ED-ADC1-A3D6CF5CC2A4","name":"b0:a7:32:81:93:e6","service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B"}
⚡️  [log] - progress bar=0

---- last block , partial  .. devices doesn't indicate received

⚡️  [log] - sending package, start=658168 end=658448
To Native Cordova ->  BluetoothLePlugin write BluetoothLePlugin620566078 ⚡️  [log] - data length = 280 data is an array true typeof=object
["options": [{
    address = "F2195DF1-3329-F489-6E77-E917B966BD9B";
    characteristic = "15c1564c-36c5-11ed-adc1-a3d6cf5cc2a4";
    service = "15c155ca-36c5-11ed-adc0-9741d6a72f04";
    type = noResponse;
    value = "EUgTECAADCIN8AAAADYhAGFPmlDmA00AYCUQOyIg5hMQIABF7f8NBFDmExAgAB3wADYhACDjEx3wOAIw5/M4EjAQEzgiMBETODIwBBM4QjAMEzhSMCATOGIwIRM4cjAiEziCMCMTOJIw6vM4ojDr8ziyMOzzDfAAAHA+4zkCMBADORIwEQM5IjAEAzkyMAwDOUIwIAM5UjAhAzliMCIDOXIwIwM5gqA+4zmSsD7jOaLAPuM5sg3wAAA2IQAMAzDkYRAgACAjICDkExAgAC0DHfA2IQAMBEDkYRAgACA0ICAzMDDkExAgAC0EHfAAAAAAAAAAAAAAAABMEhHsbNRLn+xwBMqzuTTfEUXO5T4t1M7JNuQaQsCpnng=";
}]]
⚡️  [log] - length of data =281
⚡️  [log] - sendData write rc={"status":"written","value":"EUgTECAADCIN8AAAADYhAGFPmlDmA00AYCUQOyIg5hMQIABF7f8NBFDmExAgAB3wADYhACDjEx3wOAIw5/M4EjAQEzgiMBETODIwBBM4QjAMEzhSMCATOGIwIRM4cjAiEziCMCMTOJIw6vM4ojDr8ziyMOzzDfAAAHA+4zkCMBADORIwEQM5IjAEAzkyMAwDOUIwIAM5UjAhAzliMCIDOXIwIwM5gqA+4zmSsD7jOaLAPuM5sg3wAAA2IQAMAzDkYRAgACAjICDkExAgAC0DHfA2IQAMBEDkYRAgACA0ICAzMDDkExAgAC0EHfAAAAAAAAAAAAAAAABMEhHsbNRLn+xwBMqzuTTfEUXO5T4t1M7JNuQaQsCpnng=","characteristic":"15C1564C-36C5-11ED-ADC1-A3D6CF5CC2A4","name":"b0:a7:32:81:93:e6","service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B"}
⚡️  [log] - progress bar=1

---- sendPackages loop ends
⚡️  [log] - exiting send packages loop

--- sending end (crc not calculated yet, trying to find matching  lib for Vue

⚡️  [log] - sending end
To Native Cordova ->  BluetoothLePlugin write BluetoothLePlugin620566079 ["options": [{
    address = "F2195DF1-3329-F489-6E77-E917B966BD9B";
    characteristic = "15c1564c-36c5-11ed-adc1-a3d6cf5cc2a4";
    service = "15c155ca-36c5-11ed-adc0-9741d6a72f04";
    type = noResponse;
    value = "MTIxMDBjMGEwMA==";
}]]
⚡️  [log] - length of data =10
⚡️  [log] - sendData write rc={"status":"written","value":"MTIxMDBjMGEwMA==","characteristic":"15C1564C-36C5-11ED-ADC1-A3D6CF5CC2A4","name":"b0:a7:32:81:93:e6","service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B"}

⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AA==","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}

---- done sending 

⚡️  [log] - in handle response
⚡️  [log] - resolving waitpromise
⚡️  [log] - data=[0]
⚡️  [log] - subscribe result data=0 array type=true
⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AA==","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}
⚡️  [log] - in handle response
⚡️  [log] - data=[0]
⚡️  [log] - subscribe result data=0 array type=true
⚡️  [log] - have received ok for complete
⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AA==","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}
⚡️  [log] - in handle response
⚡️  [log] - data=[0]
⚡️  [log] - subscribe result data=0 array type=true
⚡️  [log] - have received ok for complete
⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AA==","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}
⚡️  [log] - in handle response
⚡️  [log] - data=[0]
⚡️  [log] - subscribe result data=0 array type=true
⚡️  [log] - have received ok for complete
⚡️  [log] - subscribe info={"service":"15C155CA-36C5-11ED-ADC0-9741D6A72F04","address":"F2195DF1-3329-F489-6E77-E917B966BD9B","status":"subscribedResult","characteristicIndex":0,"serviceIndex":0,"value":"AA==","characteristic":"15C156E2-36C5-11ED-ADC2-7396D4FD413A","name":"b0:a7:32:81:93:e6"}
⚡️  [log] - in handle response
⚡️  [log] - data=[0]
⚡️  [log] - subscribe result data=0 array type=true
⚡️  [log] - have received ok for complete

same device code works ok w python uploader

the python uploader doesn't sleep in its send loop either


    with open(path, 'rb') as f:
        while True:
            data = f.read(attr_size - HEAD_BYTES_NUM)
            if not data:
                break

            rx_char.value = int_to_u8_bytes(PACKAGE) + list(data)
            if current_buffer_len + len(data) > buffer_size:
                if not handleResponse(tx_char.value):
                    return False
                current_buffer_len = 0
            current_buffer_len += len(data)

            uploaded_len += len(data)
            crc = zlib.crc32(data, crc)
            print(f"Uploaded: {uploaded_len}/{firmware_len}")
sdetweil commented 1 year ago

I changed the receiver characteristic to write and now I see updates at the device.

(1288×511)+280 = 658448.

but the device reports incorrect data size. 651264 7184 short 7184−(14×511). + 30

this is repeatable..

sdetweil commented 1 year ago

this is an erroneous message. it's really crc mismatch...