AM623: UART Enable PKTDMA increase total transmission time.

Gibbs Shih

Part Number: AM623

Hi, TI Expert,

Customer have uart data lose issue when baudrate works from 57600 ~ 3000,000, so I ask them add "PKTDMA" property in Linux device tree, the issue seems solved, but longer transmission is the side effect. so far, we not sure the reason. reference thread as below :

https://e2e.ti.com/support/processors-group/processors/f/processors-forum/1300416/am623-uart-dma-bcdma-or-pktdma/4937354?tisearch=e2e-quicksearch&keymatch=uart%20dma#4937354

Environment Brief :

* HW : customized board

* SW : use "serialcheck" , reference https://software-dl.ti.com/processor-sdk-linux-rt/esd/AM62X/09_00_00_03/exports/docs/linux/Foundational_Components/Kernel/Kernel_Drivers/UART.html, (section 3.2.2.17.3)

* Experiments : UART5 / UART6 "external loopback testing" with HW flow control

TEST 1 : Baud rate 115200 with flow control, no PKTDMA

am62xx-evm login: root
[   23.685465] priv->mdr1 = 0x00, priv->quot = 26
[   23.685496] default_serial_dl_write value = 26 (0x001a)
[   23.685501] UART_DLL = 0x1a
[   23.685504] UART_DLM = 0x0
[   23.685506] tmp = 0x1a
Last login: Thu Jan  1 00:00:20 UTC 1970 on ttyS2
[   23.748642] audit: type=1334 audit(28.304:8): prog-id=11 op=LOAD
[   23.748868] audit: type=1334 audit(28.304:9): prog-id=12 op=LOAD
c[   24.179072] audit: type=1006 audit(28.736:10): pid=627 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=1 res=1
[   24.179103] audit: type=1300 audit(28.736:10): arch=c00000b7 syscall=64 success=yes exit=1 a0=8 a1=ffffe97bded8 a2=1 a3=ffffb81aa020 items=0 ppid=1 pid=627 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="(systemd)" exe="/lib/systemd/systemd" key=(null)
[   24.179116] audit: type=1327 audit(28.736:10): proctitle="(systemd)"
[   24.208427] audit: type=1334 audit(28.764:11): prog-id=13 op=LOAD
[   24.208457] audit: type=1300 audit(28.764:11): arch=c00000b7 syscall=280 success=yes exit=8 a0=5 a1=ffffde89f740 a2=78 a3=0 items=0 ppid=1 pid=627 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="systemd" exe="/lib/systemd/systemd" key=(null)
[   24.208470] audit: type=1327 audit(28.764:11): proctitle="(systemd)"
[   24.208486] audit: type=1334 audit(28.764:12): prog-id=13 op=UNLOAD
[   24.208641] audit: type=1334 audit(28.764:13): prog-id=14 op=LOAD
root@am62xx-evm:~# cd /tmp/
root@am62xx-evm:/tmp# dd if=/dev/urandom of=binary count=10240 bs=1K
10240+0 records in
10240+0 records out
root@am62xx-evm:/tmp# cp binary binary11
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 115200 &
[1] 646
File of 10485760 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 115200 &
[2] 648
File of 10485760 bytes can't be locked
root@am62xx-evm:/tmp# 
Needed 0 reads 1 writes loops 1 / 1
cts: 0 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 10483328 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    15m 10.89s
user    0m 0.01s
sys     0m 0.07s
Needed 109222 reads 0 writes loops 1 / 1
cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 10485760 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done                    serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 115200
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 115200
root@am62xx-evm:/tmp#

TEST 2 : Baud rate 115200 with flow control, enable PKTDMA

am62xx-evm login: root
Last login: Thu Jan  1 00:00:28 UTC 1970 on ttyS2
[   16.683505] audit: type=1334 audit(21.364:8): prog-id=11 op=LOAD
[   16.683745] audit: type=1334 audit(21.364:9): prog-id=12 op=LOAD
[   17.145333] audit: type=1006 audit(21.824:10): pid=640 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=1 res=1
[   17.145363] audit: type=1300 audit(21.824:10): arch=c00000b7 syscall=64 success=yes exit=1 a0=8 a1=ffffe2b775b8 a2=1 a3=ffffbb6ac020 items=0 ppid=1 pid=640 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="(systemd)" exe="/lib/systemd/systemd" key=(null)
[   17.145375] audit: type=1327 audit(21.824:10): proctitle="(systemd)"
[   17.175043] audit: type=1334 audit(21.856:11): prog-id=13 op=LOAD
[   17.175073] audit: type=1300 audit(21.856:11): arch=c00000b7 syscall=280 success=yes exit=8 a0=5 a1=ffffc3b06f40 a2=78 a3=0 items=0 ppid=1 pid=640 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="systemd" exe="/lib/systemd/systemd" key=(null)
[   17.175084] audit: type=1327 audit(21.856:11): proctitle="(systemd)"
[   17.175099] audit: type=1334 audit(21.856:12): prog-id=13 op=UNLOAD
[   17.175257] audit: type=1334 audit(21.856:13): prog-id=14 op=LOAD
root@am62xx-evm:~# cd /tmp/
root@am62xx-evm:/tmp# dd if=/dev/urandom of=binary count=10240 bs=1K
10240+0 records in
10240+0 records out
root@am62xx-evm:/tmp# cp binary binary11
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 115200 &
[1] 659
File of 10485760 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 115200 &
[2] 663
File of 10485760 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 13494 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 10483975 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
Needed 6798 reads 0 writes loops 1 / 1
cts: 1 dsr: 0 rng: 0 dcd: 0 rx: 10485760 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    1h 28m 28s
user    0m 0.07s
sys     0m 0.09s

[1]-  Done                    serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 115200
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 115200
root@am62xx-evm:/tmp#

TEST 3 : Baud rate 1500000 with flow control, no PKTDMA

am62xx-evm login: root
Last login: Thu Apr 28 17:43:13 UTC 2022 on ttyS2
[   29.507894] audit: type=1334 audit(34.192:8): prog-id=11 op=LOAD
[   29.508121] audit: type=1334 audit(34.192:9): prog-id=12 op=LOAD
[   29.950971] audit: type=1006 audit(34.636:10): pid=642 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=1 res=1
[   29.950999] audit: type=1300 audit(34.636:10): arch=c00000b7 syscall=64 success=yes exit=1 a0=8 a1=ffffe8acd438 a2=1 a3=ffffbd75e020 items=0 ppid=1 pid=642 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="(systemd)" exe="/lib/systemd/systemd" key=(null)
[   29.951012] audit: type=1327 audit(34.636:10): proctitle="(systemd)"
[   29.980465] audit: type=1334 audit(34.664:11): prog-id=13 op=LOAD
[   29.980492] audit: type=1300 audit(34.664:11): arch=c00000b7 syscall=280 success=yes exit=8 a0=5 a1=fffff8b55890 a2=78 a3=0 items=0 ppid=1 pid=642 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="systemd" exe="/lib/systemd/systemd" key=(null)
[   29.980512] audit: type=1327 audit(34.664:11): proctitle="(systemd)"
[   29.980527] audit: type=1334 audit(34.664:12): prog-id=13 op=UNLOAD
[   29.980718] audit: type=1334 audit(34.664:13): prog-id=14 op=LOAD
root@am62xx-evm:~# cd /tmp/
root@am62xx-evm:/tmp# dd if=/dev/urandom of=binary count=102400 bs=1K
102400+0 records in
102400+0 records out
root@am62xx-evm:/tmp# cp binary binary11
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000 &
[1] 664
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000 &
[2] 666
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 246 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 104857600 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    12m 6.58s
user    0m 0.16s
sys     0m 0.50s

timeout, RX/TX: 104857553/0
Needed 950757 reads 0 writes Oh oh, inconsistency at pos 520774 (0x7f246).

Original sample:
0007f210: a2 28 57 fc f2 81 56 eb  43 ba b3 39 06 8b 1d 4c   .(W...V.C..9...L
0007f220: 91 e9 7d 64 39 e8 04 0a  cf 33 e0 53 b5 cd 97 74   ..}d9....3.S...t
0007f230: 0b b2 5b 5a 18 cd 88 2f  44 e3 c7 93 88 d2 7f 5b   ..[Z.../D......[
0007f240: 7c 93 2d 61 13 ba 5b 52  1a 95 f2 e1 73 13 78 09   |.-a..[R....s.x.
0007f250: 2f b3 fe 48 a3 97 1b c5  8a ce bd 24 66 09 40 17   /..H.......$f.@.
0007f260: b0 a4 da bc 89 c6 64 76  ff 4d 73 e6 ca 46 90 58   ......dv.Ms..F.X

Received sample:
0007f210: a2 28 57 fc f2 81 56 eb  43 ba b3 39 06 8b 1d 4c   .(W...V.C..9...L
0007f220: 91 e9 7d 64 39 e8 04 0a  cf 33 e0 53 b5 cd 97 74   ..}d9....3.S...t
0007f230: 0b b2 5b 5a 18 cd 88 2f  44 e3 c7 93 88 d2 7f 5b   ..[Z.../D......[
0007f240: 7c 93 2d 61 13 ba 52 1a  95 f2 e1 73 13 78 09 2f   |.-a..R....s.x./
0007f250: b3 fe 48 a3 97 1b c5 8a  ce bd 24 66 09 40 17 b0   ..H.......$f.@..
0007f260: a4 da bc 89 c6 64 76 ff  4d 73 e6 ca 46 90 58 0e   .....dv.Ms..F.X.
loops 1 / 1

cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 104857553 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done(255)               serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000 &
[1] 681
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000 &
[2] 685
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 214 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 104857600 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    12m 6.46s
user    0m 0.15s
sys     0m 0.52s

timeout, RX/TX: 104857557/0
Needed 950450 reads 0 writes Oh oh, inconsistency at pos 2715402 (0x296f0a).

Original sample:
00296ed0: 8b 3f dc 02 cd 4a c7 19  d3 48 63 f7 f0 5e bc 2d   .?...J...Hc..^.-
00296ee0: ad 0d 33 7f f1 d7 09 55  c0 9d 3a 77 d2 4f ad e1   ..3....U..:w.O..
00296ef0: 23 b6 0a 39 84 8b e6 36  06 db 8e 79 6f b3 8c b2   #..9...6...yo...
00296f00: 33 c2 ff 41 34 e3 51 b5  80 95 ed 26 9f a1 69 95   3..A4.Q....&..i.
00296f10: 36 3f 3f 60 fc cb 14 4a  48 42 6e 9a 1f 5d be 30   6??`...JHBn..].0
00296f20: f3 ab e0 2c 8c 61 1f 94  d5 4a 6e 90 ee c2 8e 58   ...,.a...Jn....X

Received sample:
00296ed0: 8b 3f dc 02 cd 4a c7 19  d3 48 63 f7 f0 5e bc 2d   .?...J...Hc..^.-
00296ee0: ad 0d 33 7f f1 d7 09 55  c0 9d 3a 77 d2 4f ad e1   ..3....U..:w.O..
00296ef0: 23 b6 0a 39 84 8b e6 36  06 db 8e 79 6f b3 8c b2   #..9...6...yo...
00296f00: 33 c2 ff 41 34 e3 51 b5  80 95 26 9f a1 69 95 36   3..A4.Q...&..i.6
00296f10: 3f 3f 60 fc cb 14 4a 48  42 6e 9a 1f 5d be 30 f3   ??`...JHBn..].0.
00296f20: ab e0 2c 8c 61 1f 94 d5  4a 6e 90 ee c2 8e 58 c8   ..,.a...Jn....X.
loops 1 / 1

cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 104857557 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done(255)               serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000
root@am62xx-evm:/tmp#

TEST 4 : Baud rate 1500000 with flow control, enable PKTDMA

am62xx-evm login: root
Last login: Thu Jan  1 00:00:54 UTC 1970 on ttyS2
[   21.544095] audit: type=1334 audit(1651167761.780:8): prog-id=11 op=LOAD
[   21.544324] audit: type=1334 audit(1651167761.780:9): prog-id=12 op=LOAD
[   22.009675] audit: type=1006 audit(1651167762.248:10): pid=582 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=1 res=1
[   22.009706] audit: type=1300 audit(1651167762.248:10): arch=c00000b7 syscall=64 success=yes exit=1 a0=8 a1=ffffe631eb78 a2=1 a3=ffffaf3a6020 items=0 ppid=1 pid=582 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="(systemd)" exe="/lib/systemd/systemd" key=(null)
[   22.009719] audit: type=1327 audit(1651167762.248:10): proctitle="(systemd)"
[   22.040106] audit: type=1334 audit(1651167762.276:11): prog-id=13 op=LOAD
[   22.040136] audit: type=1300 audit(1651167762.276:11): arch=c00000b7 syscall=280 success=yes exit=8 a0=5 a1=ffffed93abb0 a2=78 a3=0 items=0 ppid=1 pid=582 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=1 comm="systemd" exe="/lib/systemd/systemd" key=(null)
[   22.040148] audit: type=1327 audit(1651167762.276:11): proctitle="(systemd)"
[   22.040162] audit: type=1334 audit(1651167762.276:12): prog-id=13 op=UNLOAD
[   22.040348] audit: type=1334 audit(1651167762.276:13): prog-id=14 op=LOAD
root@am62xx-evm:~# cd /tmp/
root@am62xx-evm:/tmp# dd if=/dev/urandom of=binary count=102400 bs=1K
102400+0 records in
102400+0 records out
root@am62xx-evm:/tmp# cp binary binary11
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000 &
[1] 626
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000 &
[2] 630
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 102444 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 104857600 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    12m 26.62s
user    0m 0.08s
sys     0m 0.81s
Needed 51222 reads 0 writes loops 1 / 1
cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 104857600 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done                    serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000 &
[1] 665
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000 &
[2] 669
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 102446 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 104857600 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    12m 47.91s
user    0m 0.11s
sys     0m 0.78s
Needed 51222 reads 0 writes loops 1 / 1
cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 104857600 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done                    serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000
root@am62xx-evm:/tmp# serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000 &
[1] 807
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000 &
[2] 811
File of 104857600 bytes can't be locked
root@am62xx-evm:/tmp# Needed 0 reads 1 writes loops 1 / 1
cts: 102434 dsr: 0 rng: 0 dcd: 0 rx: 0 tx: 104857600 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0
real    12m 21.55s
user    0m 0.11s
sys     0m 0.79s
Needed 51217 reads 0 writes loops 1 / 1
cts: 2 dsr: 0 rng: 0 dcd: 0 rx: 104857600 tx: 0 frame 0 ovr 0 par: 0 brk: 0 buf_ovrr: 0

[1]-  Done                    serialcheck -h -d /dev/ttyS1 -f binary11 -m r -l 1 -b 1500000
[2]+  Done                    time serialcheck -h -d /dev/ttyS0 -f binary -m t -l 1 -b 1500000
root@am62xx-evm:/tmp#

Conclusion as below :

1. Base on test result, Data already do not lost when DT enable PKTDMA.
2. Data already do not lost even in high (3M bps) or low (115200 bps) uart baudrate.
3. HW Flow control is necessary.
4. Uart Baudrate is still correct after DT enable PKTDMA.
5. Base on same binary size (EX:10MB) in low baudrate (ex:115200), enable PKTDMA have “much longer” transmission time than disable PKTDMA.
6. Enable PKTDMA also increase transmission time, it’s very obviously in low baudrate.

As I mention before, base on test case 1 & 2, disable PKTDMA , 10MB data transmission just need 12min, but enable PKTDMA need 1.5 hour.

Even enable DMA saving uart bandwidth, but it increase transmission time.

About this test result, we feel confuse. Need debug direction or any suggestion?

Many Thanks

Gibbs

over 1 year ago

+1 Bin Liu over 1 year ago

TI__Guru**** 168501 points

Hi Gibbs,

For the no DMA mode, can you please test with the kernel patch below? It should fix the UART char drop issue. This patch basically removes the "UART_RX_TIMEOUT_QUIRK" flag.

Fullscreen 8250-omap-fix-char-drop-5.10.diff Download

diff --git a/drivers/tty/serial/8250/8250_omap.c b/drivers/tty/serial/8250/8250_omap.c
index 2bc6b982238f..842f3c19192e 100644
--- a/drivers/tty/serial/8250/8250_omap.c
+++ b/drivers/tty/serial/8250/8250_omap.c
@@ -1337,7 +1337,7 @@ static struct omap8250_dma_params am33xx_dma = {
 static struct omap8250_platdata am654_platdata = {
        .dma_params     = &am654_dma,
        .habit          = UART_HAS_EFR2 | UART_HAS_RHR_IT_DIS |
-                         UART_RX_TIMEOUT_QUIRK | UART_HAS_NATIVE_RS485,
+                         UART_HAS_NATIVE_RS485,
 };
 
 static struct omap8250_platdata am33xx_platdata = {

0 Gibbs Shih over 1 year ago in reply to Bin Liu

TI__Expert 5335 points

Thanks, Bin

I think customer also tracking this thread,wait his feedback.

Gibbs

0 Gibbs Shih over 1 year ago in reply to Bin Liu

TI__Expert 5335 points

Thanks Bin

Problem solved.

Ref this thread, https://e2e.ti.com/support/processors-group/processors/f/processors-forum/1217884/sk-am64b-am64-uart-8250-dma-fifo-interrupt

AM62x & AM64x has same issue.

Gibbs

Processors

Processors forum

AM623: UART Enable PKTDMA increase total transmission time.