search

fpoli / gicisky-tag

Python tools to write an image to a Gicisky tag
GNU General Public License v3.0
1 stars 0 forks source link

Stuck at sending image #1

Open agathakazar opened 1 month ago

agathakazar commented 1 month ago

Hi!

I've got the same 2.1 BWR tag, tried running this, and it's stuck at sending image:

gicisky_tag (INFO): Loading image...
gicisky_tag (INFO): Scanning...
gicisky_tag (DEBUG): Device FF:FF:92:10:88:98: NEMR92108898: AdvertisementData(local_name='NEMR92108898', manufacturer_data={20563: b'\x0b\x1d\x81\x01A'}, service_uuids=['00001800-0000-1000-8000-00805f9b34fb', '00001801-0000-1000-8000-00805f9b34fb', '0000fef0-0000-1000-8000-00805f9b34fb', '00010203-0405-0607-0809-0a0b0c0d1912'], tx_power=3, rssi=-44)
gicisky_tag (INFO): Found device FF:FF:92:10:88:98. Battery: 2.9 V
gicisky_tag (INFO): Connecting to FF:FF:92:10:88:98...
gicisky_tag (DEBUG): MTU: 247
gicisky_tag (DEBUG): Image data: 11504 bytes
gicisky_tag (INFO): Sending image data...
gicisky_tag (DEBUG): Success: block size request
gicisky_tag (DEBUG): Received block size: 244
gicisky_tag (DEBUG): Request: write screen (size: 11504)
gicisky_tag (DEBUG): Success: write screen request
gicisky_tag (DEBUG): Request: start transfer
gicisky_tag (DEBUG): Success: image transfer request
gicisky_tag (INFO): Sending image part 1/48

No transfers, no errors, no timeouts, can stay this way for hours until I ctrl+c.

fpoli commented 1 month ago

Hi! That indicates that, for some reason, the tag didn't acknowledge receiving the data. So, the script keeps waiting for an answer. Which image did you try to send? Perhaps there is a bug in the script's encoding of that particular image.

If you are you willing to debug a bit, here are some things that I'd try:

  1. Try sending a different/simpler image (e.g., 250 × 122 pixels, all white).
  2. Power-cycle the tag (removing both batteries).
  3. Make the logging more verbose, replacing logger.log(logging.NOTSET, "<message>") in the code with just logger.debug("<message>"). For example, this one.
agathakazar commented 1 month ago
  1. Tested with several different images, but still the same
  2. Power-cycling doesn't seem to help
  3. Trying to send a white-only image with debug everywhere: 
    gicisky_tag (INFO): Loading image...
gicisky_tag (INFO): Scanning...
gicisky_tag (DEBUG): Device FF:FF:92:10:88:98: NEMR92108898: AdvertisementData(local_name='NEMR92108898', manufacturer_data={20563: b'\x0b\x1d\x81\x01A'}, service_uuids=['00001800-0000-1000-8000-00805f9b34fb', '00
001801-0000-1000-8000-00805f9b34fb', '0000fef0-0000-1000-8000-00805f9b34fb', '00010203-0405-0607-0809-0a0b0c0d1912'], tx_power=3, rssi=-48)
gicisky_tag (INFO): Found device FF:FF:92:10:88:98. Battery: 2.9 V
gicisky_tag (INFO): Connecting to FF:FF:92:10:88:98...
gicisky_tag (DEBUG): MTU: 247
gicisky_tag (DEBUG): Image data: 11504 bytes
gicisky_tag (INFO): Sending image data...
gicisky_tag (DEBUG): Request: block size
gicisky_tag (DEBUG): Sending request message: [1]
gicisky_tag (DEBUG): Received notify: [1, 244, 0]
gicisky_tag (DEBUG): Success: block size request
gicisky_tag (DEBUG): Received block size: 244
gicisky_tag (DEBUG): Request: write screen (size: 11504)
gicisky_tag (DEBUG): Sending request message: [2, 240, 44, 0, 0]
gicisky_tag (DEBUG): Received notify: [2, 0, 44]
gicisky_tag (DEBUG): Success: write screen request
gicisky_tag (DEBUG): Request: start transfer
gicisky_tag (DEBUG): Sending request message: [3]
gicisky_tag (DEBUG): Received notify: [5, 0, 0, 0, 0, 0]
gicisky_tag (DEBUG): Success: image transfer request
gicisky_tag (INFO): Sending image part 1/48
gicisky_tag (DEBUG): Sending image message: [0, 0, 0, 0, 236, 44, 0, 0, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 2
55, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255,
255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 25
5, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255,
255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255
, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0]

    What are the 240, 44 in the second request part and the 44 in the reply?

fpoli commented 1 month ago

What are the 240, 44 in the second request part and the 44 in the reply?

240, 44, 0, 0 is the little-endian encoding of the size of the image, in bytes. In decimal it's 11504.

I'm not sure what's the final 44 in the reply. According to the only protocol documentation that I'm aware of (https://zhuanlan.zhihu.com/p/633113543), that reply should only be 2 bytes long. That's the only difference between my log and yours.

My log:

...
gicisky_tag (DEBUG): MTU: 247
gicisky_tag (DEBUG): Image data: 11504 bytes
gicisky_tag (INFO): Sending image data...
gicisky_tag (DEBUG): Request: block size
gicisky_tag (DEBUG): Sending request message: [1]
gicisky_tag (DEBUG): Received notify: [1, 244, 0]
gicisky_tag (DEBUG): Success: block size request
gicisky_tag (DEBUG): Received block size: 244
gicisky_tag (DEBUG): Request: write screen (size: 11504)
gicisky_tag (DEBUG): Sending request message: [2, 240, 44, 0, 0]
gicisky_tag (DEBUG): Received notify: [2, 0]
gicisky_tag (DEBUG): Success: write screen request
gicisky_tag (DEBUG): Request: start transfer
gicisky_tag (DEBUG): Sending request message: [3]
gicisky_tag (DEBUG): Received notify: [5, 0, 0, 0, 0, 0]
gicisky_tag (DEBUG): Success: image transfer request
gicisky_tag (INFO): Sending image part 1/48
gicisky_tag (DEBUG): Sending image message: [0, 0, 0, 0, 236, 44, 0, 0, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0, 0, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 192, 117, 23, 16, 0, 0, 0]
gicisky_tag (DEBUG): Received notify: [5, 0, 1, 0, 0, 0]
gicisky_tag (DEBUG): Success: image transfer request
gicisky_tag (INFO): Sending image part 2/48
...
fpoli commented 1 month ago

Actually, there is one more difference in the last service that is advertised, but I don't know its purpose.

From your log:

service_uuids=['00001800-0000-1000-8000-00805f9b34fb', '00001801-0000-1000-8000-00805f9b34fb', '0000fef0-0000-1000-8000-00805f9b34fb', '00010203-0405-0607-0809-0a0b0c0d1912']

From my log:

service_uuids=['00001800-0000-1000-8000-00805f9b34fb', '00001801-0000-1000-8000-00805f9b34fb', '0000fef0-0000-1000-8000-00805f9b34fb', 'f000ffc0-0451-4000-b000-000000000000']
agathakazar commented 1 month ago

difference in the last service that is advertised

That is listed as Telink OTA

protocol documentation

Paragraph 8 lists manufacturerId and some service data (my tag reports 53 50 0b 1d 81 01 41) Do you also have 81 01 in there? That's supposedly the software and hardware version. The 0b and 41 could also be significant, being the device type but I couldn't match it to anything that is in the table 1 mentioned.

fpoli commented 1 month ago

My tag reports 53 50 0b 1e 01 01 01 (manufacturer_data={20563: b'\x0b\x1e\x01\x01\x01'}), so it might be that my tag uses an earlier firmware version.

agathakazar commented 2 weeks ago

I did a bit of sniffing, and it seems that the android app is doing something differently:

From what I can see the difference in behavior starts here, first is the android app and second is gicisky-tag:

33  2.735   Master_0x64a546d5   LE 1M   ATT 11  48381µs 0   0   False   14  Sent Read By Type Request, Include, Handles: 0x0001..0x0007
59  3.179   Master_0xf5f68e26   LE 1M   ATT 11  44630µs 1   1   False   25  Sent Read By Type Request, Include, Handles: 0x0001..0x0019

And as a response following those android app returns less data:

42  2.852   Slave_0x64a546d5    LE 1M   ATT 27  149µs   0   1   False   18  Rcvd Read By Type Response, Attribute List Length: 3, Device Name, Appearance, Peripheral Preferred Connection Parameters

And gicisky-tag more:

65  3.314   Slave_0xf5f68e26    LE 1M   ATT 48  149µs   0   1   False   28  Rcvd Read By Type Response, Attribute List Length: 6, Device Name, Appearance, Peripheral Preferred Connection Parameters, Service Changed, CSR, CSR

But I'm not sure what all this means.

I've also noticed a couple of MTU warnings, but those are probably insignificant since it's the data returned from the tag Expert Info (Warning/Protocol): Packet size exceed current ATT_MTU

The capture files are here: https://share.svalka.tel:5281/file_share/ff022683-e90b-463b-be33-2d7a36d1e0f1/android_bletag_white.pcapng https://share.svalka.tel:5281/file_share/7f276563-7e24-4823-99c8-a4c5970065fc/gicisky_tag_writer.pcapng

fpoli commented 2 weeks ago

In the gicisky_tag_writer.pcapng I think that the frames of the image transmission are these: image Each frame corresponds to one of the messages in the augmented debug log that you posted. In Wireshark, I was able to identify them using the filter btatt.value. The frame number 117 is the one that contains three bytes (02 00 2c) instead of just two.

If I try the same btatt.value filter on the android_bletag_white.pcapng dump, I don't get any results. Are you sure that you correctly captured all messages? If the dump is correct, it would mean that the transmission uses a completely different protocol, but that seems unlikely to me.