This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

Linux/WL1831MOD: Datacorruption on bluetooth !

Part Number: WL1831MOD
Other Parts Discussed in Thread: WL1831

Tool/software: Linux

Hello ,

TI-WL1831 . 

We are experiencing data corruption on RFCOMM. (we are testing with 2 service packs version 4.2 and 3.9, both have similar bit errors in the data !)

Test scenario we use ONE-Bluetooth master ( bluegiga WT41 ) connecting to multiple bluetooth slaves ( WL1831).

The test sends one GENERATED DATA FRAME containing some header and data bytes 00, 01, 02 ... till FE. after some hours of loopback it happens occasionally ( 1a2 frames on 100.000) that  we get faulty data-bytes.

( FYI each in and out going action, the generated data frame is checked on different levels, application  and kernel driver just before sending to the ACIA ( in the HCI_LL driver) and or just after receiving on the acia.

Acia baud rate ( 3000000 baud) has been checked with an 'infinite persistence' scope for several hours, bits have no jitter, and levels are ok! 

This is an example of an error data frame. ( for some reason if an error happens... the error frame is 'NOT' ok, some bits ( in a byte) are missing or shifted to next bit position in the bytes)

This error FRAME is being logged when we get the data into the HCI_LL driver ( received by the host cpu , after getting the bytes out of the ACIA) marked faulty bytes are colored RED and underlined,

Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764375] [KERNEL] DUMP-DIFF !!!!!
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764410] RX-BUF [len=00304]
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764527] [0x0000] 01 00 03 00 00 09 00 00 00 02 00 00 00 00 00 00 FF FF 04 00 FF 02 00 00 00 01 00 00 00 FF 00 00 00 00 00 FF 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764638] [0x0040] 1C 1D 1E 1F 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F 50 51 52 53 54 55 56 57 58 59 5A 5B
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764748] [0x0080] 5C 5D 5E 5F 60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77 78 79 7A 5B 7C 7D 7E 5F 80 81 82 83 84 85 86 97 88 89 8A 8B 8C 8D 8C 8F 90 91 92 93 94 95 96 97 98 99 9A 9B
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764858] [0x00C0] 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB
Mar 28 05:56:17 DU9 kern.warn kernel: [152851.764931] [0x0100] DC DD DE DF E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE BF 49 2F 72 65 71 75 65 73 74 6D 64 69

Finally this 'same' error pops-also up in the application software ... printing out the WRONG bytes ( first print out is just behind the socket read in the application)

Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] BEGIN - LOG
Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] OFFSET 0x007B : 0x7B <=> 0x5B
Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] OFFSET 0x007F : 0x7F <=> 0x5F
Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] OFFSET 0x0087 : 0x87 <=> 0x97
Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] OFFSET 0x008E : 0x8E <=> 0x8C
Mar 28 05:56:18 DU9 user.info BMS_DUTEST_0 [24818]: [ModLoopbackDUMsg] END - LOG

Any hints on how to proceed ? 

Is there any possibility to log the data-bytes over the serial line with the Ti-logger application  ( I can see many things there , but I don't find a way to see serial DATA-BYTES on HCI_LL level ! )

Best Regards

Noel Vellemans

FYI:

1) this error is never seen on a bluegiga vs bluegiga setup.

2) it can take up to more than a day to get this 'error'.

  • Hello Noel,

    Unfortunately there is no possibility to log data-bytes over the serial line with the TI-logger application.
    You can use a Hci Sniffer to log all data going over the UART lines - external tool.

    I'm not familiar with this issue and it seems to be very hard to reproduce as you've mentioned here.

    Can you please try and capture such an occurrence and send us the FW logs and hopefully the HCI UART logs.
    This will help us look into this issue.

    BR,
    Chen Loewy
  • Hi Chen,

    Chen I've been looking into this matter for more then 3-weeks , and I did add checks on different places in the linux-kernel ( I even went down to the HCI_LL drivers... And I'm printing out "faulty" frames on both send and receive sides )

    When ever I trap such an error frame it is always on the receive-side of the host CPU ( this means WL1831 is sending bytes to the receiving host cpu, what is an IMX53 in our case).


    I did trap many frames in those 3 weeks.. and checks are happening on different places/layers in the code .. but bottom line it the first error frame is always seen in the receiving side of the host CPU !



    I have the logger open ( TI-logger application) on my PC , but I can't get much useful info .. from this ... ( before the error occurs there have been send lots ( 10000ths) of correct frames... and it is very occasionally when it fails, as soon as an error occurs, I stop the loop-back operation.)

    At this particular time , I have the impression that the data-corruption is less-occurring on the 4.2 service pack compared to 3.9 ( but I can not be sure on this since it often takes very long to get into this error situation)


    Are you aware on older firmware ( like for example 3.9sp , of such data corruptions, in other words, should I log both, 4.2 and 3.9 firmwares, if you are aware of a problem case in older firmwares, i'll upgrade all in-lab devices to 4.2 service pack)



    just for into this morning I had trapped another occurrence ... ( just 1 minute before I got your mail)



    ** This is logged ... on the HCI_LL layer ( when pulling bytes out of the SERIAL port on the linux host)

    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684276] [KERNEL] DUMP-DIFF !!!!!
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684308] RX-BUF [len=00304]
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684424] [0x0000] 01 00 03 00 00 0A 00 00 00 02 00 00 00 00 00 00 FF FF 04 00 FF 02 00 00 00 01 00 00 00 FF 00 00 00 00 00 FF 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684535] [0x0040] 1C 1D 1E 1F 20 21 22 23 24 25 20 27 20 89 2A 29 2C 2C 2B EF 93 37 3A 33 34 35 36 35 28 39 3A 3B 3C 3D 3F 3A 40 41 42 4A 04 0D C6 07 59 49 CA D3 4C 4D 4E 4F 50 51 52 53 54 55 56 57 58 59 5A 5B
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684645] [0x0080] 5C 5D 5E 5F 60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90 91 92 93 94 95 96 97 98 99 9A 9B
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684755] [0x00C0] 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB
    Mar 28 08:07:33 DU9 kern.warn kernel: [85269.684828] [0x0100] DC DD DE DF E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE BF 65 71 75 65 73 74 6D 64 69 64 2E 66






    ** This is logged into the application ( user land application).

    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] BEGIN - LOG
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0026 : 0x26 <=> 0x20
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0028 : 0x28 <=> 0x20
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0029 : 0x29 <=> 0x89
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x002B : 0x2B <=> 0x29
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x002D : 0x2D <=> 0x2C
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x002E : 0x2E <=> 0x2B
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x002F : 0x2F <=> 0xEF
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0030 : 0x30 <=> 0x93
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0031 : 0x31 <=> 0x37
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0032 : 0x32 <=> 0x3A
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0037 : 0x37 <=> 0x35
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0038 : 0x38 <=> 0x28
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x003E : 0x3E <=> 0x3F
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x003F : 0x3F <=> 0x3A
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0043 : 0x43 <=> 0x4A
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0044 : 0x44 <=> 0x04
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0045 : 0x45 <=> 0x0D
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0046 : 0x46 <=> 0xC6
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0047 : 0x47 <=> 0x07
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x0048 : 0x48 <=> 0x59
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x004A : 0x4A <=> 0xCA
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] OFFSET 0x004B : 0x4B <=> 0xD3
    Mar 28 08:07:34 DU9 user.info BMS_DUTEST_0 [5421]: [ModLoopbackDUMsg] END - LOG


    One more thing I want to say ( the error seems to occur on different Linux kernel versions 2.6.35.xx and 4.4.xx, at this time logs are running on a Linux DU9 4.4.115 )



    What I wonder is, how it is possible that those frames are passing checksum-verifications ( on both WL1831 module and Linux-kernel) ?

    I will try to grab all you ask me when it occurs next time !

    Logging low level hardware-wise (the acia bytes) is not an easy operation, I have to connect ( some hardware) to vias ( if possible ??) on the multilayer PCB. ( WL1831 module is fit on board, it is not external)


    A HCI sniffer won't bring me much more... because I've been adding logging functionality to the HCI_LL drivers ( what is even lower level then the HCI sniffer) { first print out in this message, at kernel level, is the HCI_LL receive print out .. those are the acia bytes that are injected into the HCI-receiving layers , and on this level the error is already present ! }




    Regards
    Noel


    PS: I was trying to insert code ( that shows you where the print-out's are taken , but web-site bails out with an error message I should contact admin)
  • Hi chen, 

    I was able to trap another issue....

    TI-WL1831 Servicepack 4.2 , linux kernel - 4.4.115 ( with custom logger in HCI_LL driver)

    As said before correct-data bytes contains pattern 00, 01 , 02.... till FE !! 

    logs: 

    *Kernel-MODE-dump - in HCI_LL driver , after pulling bytes out of acia!

    Mar 28 13:39:37 DU9 kern.warn kernel: [15778.960257] HCILL_WAKE_UP_ACK packet

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.661697] [KERNEL] DUMP-DIFF !!!!!

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.661732] RX-BUF [len=00304]

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.661847] [0x0000] 01 00 03 00 00 09 00 00 00 02 00 00 00 00 00 00 FF FF 04 00 FF 02 00 00 00 01 00 00 00 FF 00 00 00 00 00 FF 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.661958] [0x0040] 1C 1D 1E 1F 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F 50 51 52 53 54 55 56 57 58 59 5A 5B

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.662068] [0x0080] 5C 5D 5E 5F 60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90 91 92 93 94 95 96 97 98 99 9A 9B

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.662179] [0x00C0] 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB

    Mar 28 13:39:59 DU9 kern.warn kernel: [15800.662252] [0x0100] DC DD DE DF E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EC EF F0 F1 F3 F3 E0 75 F7 E3 F8 D9 FA 7B FC FD FE 55 6D 64 69 64 2E 66 63 67 69 0C 00 51

    *1st app  layer  - ( after scoket READ)

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] BEGIN - LOG

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00EE : 0xEE <=> 0xEC

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00F2 : 0xF2 <=> 0xF3

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00F4 : 0xF4 <=> 0xE0

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00F5 : 0xF5 <=> 0x75

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00F6 : 0xF6 <=> 0xF7

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] OFFSET 0x00F7 : 0xF7 <=> 0xE3

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [ModLoopbackDUMsg] END - LOG

    * 2nd app layer

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] BEGIN - LOG

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00EE : 0xEE <=> 0xEC

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00F2 : 0xF2 <=> 0xF3

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00F4 : 0xF4 <=> 0xE0

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00F5 : 0xF5 <=> 0x75

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00F6 : 0xF6 <=> 0xF7

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] OFFSET 0x00F7 : 0xF7 <=> 0xE3

    Mar 28 13:40:00 DU9 user.info BMS_DUTEST_0  [456]: [WDLCOMM] END - LOG

    I have tried to include the corresponding TI-logger file but it did not work . ( in zipped format is 35 MB which is above the allowed size of 20MB) ,

     Best regards

    Noel

  • Hello Noel,

    I apologize for the slow response.

    Due to the holidays here the last week I still don't have any new approach to this issue.
    I will look at it early next week once i'm back in office.

    BR,
    Chen Loewy
  • Hi all,

    Any clue on how to proceed ?

    I still keep on getting 'occasionally' ( lets say 1a2 error frames on 100.000 rfcomm frames)  RFCOMM-data errors when communicating between a Ti-WL18xx and a Bluecore4-based CSR chip.

    Best Regards

    Noel