FAQ: [#6732] mcapi message case fails frequently(2011)

Document created by Aaronwu Employee on Sep 12, 2013
Version 1Show Document
  • View in full screen mode

[#6732] mcapi message case fails frequently

Submitted By: Mingquan Pan

Open Date

2011-08-16 03:58:42     Close Date

2011-09-01 03:56:51

Priority:

Medium     Assignee:

steven miao

Status:

Closed     Fixed In Release:

N/A

Found In Release:

2011R1     Release:

Category:

N/A     Board:

N/A

Processor:

ALL     Silicon Revision:

Is this bug repeatable?:

Yes     Resolution:

Fixed

Uboot version or rev.:

    Toolchain version or rev.:

5013

App binary format:

N/A     

Summary: mcapi message case fails frequently

Details:

 

mcapi message fails frequently, sometimes because data get lost,like CoreB send back 4 round of data while CoreA sometimes would miss one of them and only get 3 which makes the case always wait for the next message and never finished. Sometimes msg1 would have dump info:

 

msg1:

...

MCAPI_DEBUG:index 100 100

MCAPI_DEBUG:mcapi_trans_valid_endpoint endpoint=0x64 (database indices: n=0,e=100) rc=1

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

sm_debug:session status index 0, avail 0

MCAPI_DEBUG:mcapi_trans_msg_available avail = 0

sm_debug:feb1f100 COREB: sm_send_message_internal() dst 0 src 1 4000000

sm_debug:       67 : 66

sm_debug:received 67

sm_debug:sm_find_session bits 00000001 localep 100

sm_debug:index 0 ,local ep 100 type 4

sm_debug:session 027c6800 index 0 msg type4000000

sm_debug:sm_default_recvmsg msg type 4000000

sm_debug:msg_recv_internal wakeup wait thread

sm_debug:received 68

sm_debug:feb1f200 COREB: endpoint=65541 has sent: [1Hello MCAPI]

sm_debug:       69 : 67

sm_debug:received 69

sm_debug:feb1f280 COREB: WRONG: line==58

sm_debug:       70 : 69

sm_debug:received 70

sm_debug:feb1f300 COREB:

222222222222222. The 1 time send back ok.

sm_debug:       71 : 70

sm_debug:received 71

sm_debug:feb1f380 COREB:

CoreB: mcapi message loop test. The 1 time send back ok.

sm_debug:       72 : 71

sm_debug:received 72

MCAPI_DEBUG:domain 0 node 0 endpoint 100sm_debug:ioctl type 0

 

MCAPI_DEBUG:index 100 100

MCAPI_DEBUG:mcapi_trans_valid_endpoint endpoint=0x64 (database indices: n=0,e=100) rc=1

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

sm_debug:session status index 0, avail 1

sg_available avail = 1 0

 

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

MCAPI_DEBUG:mcapi_trans_valid_endpoint endpoint=0x64 (database indices: n=0,e=100) rc=1

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

session_idx 0

sm_debug:recv sleep on queue index sm_recv_packet index 0

sm_debug:recv 1Hello MCAPI

sm_debug:sm_send_message_internal: dst 1 src 0

sm_debug:send message cpu 1 sent 7

sm_debug:feb1f000 COREB: sm_handle_control_message type 4000000

sm_debug:       73 : 72

sm_debug:received 73

MCAPI_DEBUG:index 0, se 5, sn 1

MCAPI_DEBUG:buffer 1Hello MCAPI

node=1, port=5

endpoint=100 has received: [1Hello MCAPI]

CoreA : message recv. The 1 time receiving ok, status 1

sm_debug:feb1f080 COREB: index 0 ,local ep 5

sm_debug:       74 : 73

sm_debug:received 74

sm_debug:feb1f100 COREB: msg type 4000000 index 0 session type 4

sm_debug:       75 : 74

sm_debug:received 75

sm_debug:feb1f180 COREB: type 4000000, dstep 5, srcep 100

sm_debug:       76 : 75

sm_debug:received 76

sm_debug:feb1f200 COREB: recved packet msg handle0

sm_debug:       77 : 76

sm_debug:received 77

MCAPI_DEBUG:domain 0 node 0 endpoint 100sm_debug:ioctl type 0

 

MCAPI_DEBUG:index 100 100

MCAPI_DEBUG:mcapi_trans_valid_endpoint endpoint=0x64 (database indices: n=0,e=100) rc=1

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

sm_debug:feb1f280 COREB: msg_recv_internal msg type 4000000 alloc 3d400c0

sm_debug:       78 : 77

sm_debug:received 78

sm_debug:session status index 0, avail 0

MCAPI_DEBUG:mcapi_trans_msg_available avail = 0

sm_debug:feb1f300 COREB: avail 1

sm_debug:       79 : 78

sm_debug:received 79

sm_debug:feb1f380 COREB: index 0 avail 1

sm_debug:       80 : 79

sm_debug:received 80

sm_debug:feb1f000 COREB:

1111111111111. The 2 time send back ok.

sm_debug:       81 : 80

sm_debug:received 81

sm_debug:feb1f080 COREB: mcapi_trans_valid_endpoint ep 65541 index 0 valid 1

sm_debug:       82 : 81

sm_debug:received 82

sm_debug:feb1f100 COREB:  sm_recv_packet session type 4 localep5

sm_debug:       83 : 82

sm_debug:received 83

MCAPI_DEBUG:domain 0 node 0 endpoint 100sm_debug:ioctl type 0

 

MCAPI_DEBUG:index 100 100

MCAPI_DEBUG:mcapi_trans_valid_endpoint endpoint=0x64 (database indices: n=0,e=100) rc=1

MCAPI_DEBUG:domain 0 node 0 endpoint 100

MCAPI_DEBUG:index 100 100

sm_debug:session status index 0, avail 0

MCAPI_DEBUG:mcapi_trans_msg_available avail = 0

sm_debug:feb1f180 COREB: sm_recv_packet() 1Hello MCAPI

sm_debug:       84 : 83

sm_debug:received 84

sm_debug:feb1f200 COREB:  sm_recv_packet msg

sm_debug:       85 : 84

sm_debug:received 85

sm_debug:feb1f280 COREB: buffer 1Hello MCAPI len 12 se 100 sn 0

sm_debug:       86 : 85

sm_debug:received 86

sm_debug:feb1f300 COREB: sm_send_message_internal() dst 0 src 1 4000001

sm_debug:       87 : 86

sm_debug:received 87

sm_debug:sm_find_session bits 00000001 localep 100

sm_debug:index 0 ,local ep 100 type 4

sm_debug:session 027c6800 index 0 msg type4000001

sm_debug:sm_default_recvmsg msg type 4000001

sm_debug:unmatched ack 027bce80 c uncomplete tx 027bce00

sm_debug:unmatched ack 027bce80 c uncomplete tx 027bce40

sm_debug:ack matched free buf 27bce80

NULL pointer access

Kernel OOPS in progress

Deferred Exception context

CURRENT PROCESS:

COMM=iccqd PID=148  CPU=0

invalid mm

return address: [0x000c904a]; contents of:

0x000c9020:  1893  0000  0000  0000  a161  a09b  0819  1095

0x000c9030:  e140  0015  e100  f5d0  e302  c8e4  ac61  9162

0x000c9040:  e120  1001  4f40  e121  0798 [bc51] 934a  9320

0x000c9050:  e120  1001  4f48  b060  917a  a050  5008  e3c9

 

ADSP-BF561-0.3(Detected 0.5) 600(MHz CCLK) 100(MHz SCLK) (mpu off)

Linux version 3.0.0-ADI-2011R1-pre-svn10045 (test@adsl) (gcc version 4.3.5 (ADI-2010R1-RC4) ) #160 Tue Aug 16 15:20:55 CST 2011

 

SEQUENCER STATUS:               Not tainted

SEQSTAT: 00002027  IPEND: 8008  IMASK: ffff  SYSCFG: 0006

  EXCAUSE   : 0x27

  physical IVG3 asserted : <0xffa00834> { _trap + 0x0 }

  physical IVG15 asserted : <0xffa01118> { _evt_system_call + 0x0 }

  logical irq   6 mapped  : <0xffa00448> { _bfin_coretmr_interrupt + 0x0 }

  logical irq  35 mapped  : <0x000ac60c> { _bfin_serial_dma_rx_int + 0x0 }

  logical irq  36 mapped  : <0x000ac354> { _bfin_serial_dma_tx_int + 0x0 }

  logical irq  69 mapped  : <0x0000ac48> { _ipi_handler_int0 + 0x0 }

  logical irq  70 mapped  : <0x0000abfc> { _ipi_handler_int1 + 0x0 }

  logical irq  82 mapped  : <0x000c6430> { _smc_interrupt + 0x0 }

RETE: <0x00000000> /* Maybe null pointer? */

RETN: <0x027b5f68> /* kernel dynamic memory (maybe user-space) */

RETX: <0x00000480> /* Maybe fixed code section */

RETS: <0x000c903c> { _sm_default_recvmsg + 0x228 }

PC  : <0x000c904a> { _sm_default_recvmsg + 0x236 }

DCPLB_FAULT_ADDR: <0x00000004> /* Maybe null pointer? */

ICPLB_FAULT_ADDR: <0x000c904a> { _sm_default_recvmsg + 0x236 }

PROCESSOR STATE:

R0 : 00100100    R1 : 00000798    R2 : ffffffff    R3 : 00004c56

R4 : 00000000    R5 : 00000001    R6 : 00000000    R7 : 00000000

P0 : 00000c55    P1 : feb1f200    P2 : 00000001    P3 : feb18074

P4 : 027bcf00    P5 : 027c6800    FP : 00189854    SP : 027b5e8c

LB0: ffa01854    LT0: ffa01852    LC0: 00000000

LB1: 00097dce    LT1: 00097dc4    LC1: 00000000

B0 : 0000001b    L0 : 00000000    M0 : ffffffff    I0 : 00000000

B1 : 00000000    L1 : 00000000    M1 : 00000000    I1 : 0012a5c8

B2 : 00000000    L2 : 00000000    M2 : 00000000    I2 : 00000020

B3 : 00000000    L3 : 00000000    M3 : 00000000    I3 : 0000000f

A0.w: 014de1c3   A0.x: 00000000   A1.w: 00008319   A1.x: 00000000

USP : 00000000  ASTAT: 02003004

 

Hardware Trace:

   0 Target : <0x00004058> { _trap_c + 0x0 }

     Source : <0xffa007c8> { _exception_to_level5 + 0xa4 } JUMP.L

   1 Target : <0xffa00724> { _exception_to_level5 + 0x0 }

     Source : <0xffa005d8> { _bfin_return_from_exception + 0x20 } RTX

   2 Target : <0xffa005b8> { _bfin_return_from_exception + 0x0 }

     Source : <0xffa0067c> { _ex_trap_c + 0x74 } JUMP.S

   3 Target : <0xffa00608> { _ex_trap_c + 0x0 }

     Source : <0xffa004e0> { _ex_workaround_261 + 0x1c } JUMP.S

   4 Target : <0xffa004c4> { _ex_workaround_261 + 0x0 }

     Source : <0xffa0089c> { _trap + 0x68 } JUMP (P4)

   5 Target : <0xffa00852> { _trap + 0x1e }

     Source : <0xffa0084e> { _trap + 0x1a } IF CC JUMP pcrel

   6 Target : <0xffa00834> { _trap + 0x0 }

      FAULT : <0x000c904a> { _sm_default_recvmsg + 0x236 } W[P2 + 1] = P1

     Source : <0xffa005d8> { _bfin_return_from_exception + 0x20 } RTX

   7 Target : <0xffa005b8> { _bfin_return_from_exception + 0x0 }

     Source : <0xffa004d6> { _ex_workaround_261 + 0x12 } IF !CC JUMP pcrel

   8 Target : <0xffa004c4> { _ex_workaround_261 + 0x0 }

     Source : <0xffa0089c> { _trap + 0x68 } JUMP (P4)

   9 Target : <0xffa00852> { _trap + 0x1e }

     Source : <0xffa0084e> { _trap + 0x1a } IF CC JUMP pcrel

  10 Target : <0xffa00834> { _trap + 0x0 }

     Source : <0x000c9046> { _sm_default_recvmsg + 0x232 } 0xe1210798

  11 Target : <0x000c903c> { _sm_default_recvmsg + 0x228 }

     Source : <0x00122214> { _printk + 0x14 } RTS

  12 Target : <0x00122210> { _printk + 0x10 }

     Source : <0x00012308> { _vprintk + 0x164 } RTS

  13 Target : <0x000122fc> { _vprintk + 0x158 }

     Source : <0xffa00d9a> { __common_int_entry + 0xda } RTI

  14 Target : <0xffa00d38> { __common_int_entry + 0x78 }

     Source : <0xffa00b74> { _return_from_int + 0x58 } RTS

  15 Target : <0xffa00b74> { _return_from_int + 0x58 }

     Source : <0xffa00b4a> { _return_from_int + 0x2e } IF !CC JUMP pcrel

Kernel Stack

Stack info:

SP: [0x027b5ec4] <0x027b5ec4> /* kernel dynamic memory (maybe user-space) */

FP: (0x027b5fa0)

Memory from 0x027b5ec0 to 027b6000

027b5ec0: ffa01852 [00000000] 00000000  00008319  00000000  014de1c3  00000000  00000000

027b5ee0: 00000000  00000000  0000001b  00000000  00000000  00000000  00000000  00000000

027b5f00: 00000000  00000000  ffffffff  0000000f  00000020  0012a5c8  00000000  00000000

027b5f20: 00189854  027c6800  027bcf00  feb18074  00000001  feb1f200  00000c55  00000000

027b5f40: 00000000  00000001  00000000  00004c56  ffffffff  00000798  00100100  00100100

027b5f60: 00000c55  00000006  000c8bf6  027bce80  ffffffff  027bce40  027c6808  00000000

027b5f80: 000c8d3c  027b4000  00189854  00000000  00000000  00000007  027b4000  027b4000

027b5fa0:(00000000)

0201bf68  000c8cd8  00000000  feb18000  00000000  00000000

027b5fc0: 00000000  00000000  00000000  0002490c  00000000  feb18000  00000000  027b5fdc

027b5fe0: 027b5fdc

00000000  00000000  00000000  00000000  ffffffff  00000006

Return addresses in stack:

   frame  1 : <0x00024968> { _kthread + 0x5c }

    address : <0x00001556> { _kernel_thread_helper + 0x6 }

Modules linked in:

Kernel panic - not syncing: Kernel exception

Hardware Trace:

Stack info:

SP: [0x027b5d94] <0x027b5d94> /* kernel dynamic memory (maybe user-space) */

FP: (0x027b5fa0)

Memory from 0x027b5d90 to 027b6000

027b5d90: 00000013 [0014f304] 001220cc  027b5e8c  0014f304  001814bb  001814bb  001814bb

027b5db0: 027b5ddc  00189854  00004528  027b5e8c  ffe02014  feb18074  00008008  0000000b

027b5dd0: 00000027  00000013  027b5e8c  0000003f  ffffffff  ffa00d32  ffc00014  0003000b

027b5df0: 00000003  00000003  00000020  00000020  000122fc  00008050  00002000  00000000

027b5e10: 027de000  02983402  000122fc  00012416  00000006  02003004  00097dce  ffa01854

027b5e30: 00097dc4  ffa01852  00000000  00000000  00008319  00000000  014de1c3  00000000

027b5e50: 00000000  00000000  00000000  0000001b  00000000  00000000  ffa007cc  0017e000

027b5e70: 00008008  00002027  00000001  00000000  0000000f  00000020  00000480  00000480

027b5e90: 00008008  00002027  00000000  027b5f68  00000480  000c904a  000c903c  00100100

027b5eb0: 02003004  00097dce  ffa01854  00097dc4  ffa01852  00000000  00000000  00008319

027b5ed0: 00000000  014de1c3  00000000  00000000  00000000  00000000  0000001b  00000000

027b5ef0: 00000000  00000000  00000000  00000000  00000000  00000000  ffffffff  0000000f

027b5f10: 00000020  0012a5c8  00000000  00000000  00189854  027c6800  027bcf00  feb18074

027b5f30: 00000001  feb1f200  00000c55  00000000  00000000  00000001  00000000  00004c56

027b5f50: ffffffff  00000798  00100100  00100100  00000c55  00000006  000c8bf6  027bce80

027b5f70: ffffffff  027bce40  027c6808  00000000  000c8d3c  027b4000  00189854  00000000

027b5f90: 00000000  00000007  027b4000  027b4000 (00000000)

0201bf68  000c8cd8

027b5fb0: 00000000  feb18000  00000000  00000000  00000000  00000000  00000000  0002490c

027b5fd0: 00000000  feb18000  00000000  027b5fdc  027b5fdc

00000000  00000000

027b5ff0: 00000000  00000000  ffffffff  00000006

Return addresses in stack:

   frame  1 : <0x00024968> { _kthread + 0x5c }

    address : <0x00001556> { _kernel_thread_helper + 0x6 }

 

 

U-Boot 2010.06 (ADI-2010R1-RC2) (Oct 20 2010 - 04:41:42)

 

CPU:   ADSP bf561-0.3 (Detected Rev: 0.5) (bypass boot)

Board: ADI BF561 EZ-Kit Lite board

       Support: http://blackfin.uclinux.org/

Clock: VCO: 600 MHz, Core: 600 MHz, System: 100 MHz

RAM:   64 MiB

Flash: 8 MiB

In:    serial

Out:   serial

Err:   serial

KGDB:  [on serial] ready

Net:   SMC91111-0

Hit any key to stop autoboot:  0

 

Follow-ups

 

--- steven miao                                              2011-08-24 02:49:57

messages on tx list was overwriten by memcpy when recv icc msg, now it should be

fixed

 

--- Mingquan Pan                                             2011-08-25 22:58:09

After fixing ,this case runs stable than ever, and not see dump info now.

 

But it still prints some wrong line in between which needs some investigation.

 

CoreA : message recv. The 1 time receiving ok, status 1

COREB: mcapi_trans_valid_endpoint ep 65541 index 0 valid 1

COREB:  sm_recv_packet session type 4 localep5

COREB: sm_recv_packet() 1Hello MCAPI

COREB:  sm_recv_packet msg

COREB: buffer 1Hello MCAPI len 12 se 100 sn 0

COREB: sm_send_message_internal() dst 0 src 1 4000001

sm_debug:sm_find_session bits 00000001 localep 100

sm_debug:index 0 ,local ep 100 type 4

sm_debug:session 02a05828 index 0 msg type4000001

sm_debug:sm_default_recvmsg msg type 4000001

sm_debug:ack matched free buf 2a13a00 message 02a139e0 02a05830 02a13a20

COREB: free message 3d40080

COREB: endpoint=65541 has received: [1Hello MCAPI]

COREB: endpoint=100 sendback: buf 3c04cdc

COREB: mcapi_trans_valid_endpoint ep 65541 index 0 valid 1

COREB: index 0, se 5, sn 1

COREB: index 0, re 100, rn 0

COREB: sm_default_sendmsg msg type 4000000

COREB: sm_send_message_internal() dst 0 src 1 4000000

sm_debug:sm_find_session bits 00000001 localep 100

sm_debug:index 0 ,local ep 100 type 4

sm_debug:session 02a05828 index 0 msg type4000000

sm_debug:sm_default_recvmsg msg type 4000000

sm_debug:msg_recv_internal wakeup wait thread

COREB: endpoint=65541 has sent: [1Hello MCAPI]

COREB: WRONG: line==58

COREB:

CoreB: mcapi message loop test. The 3 time send back ok.

COREB: index 0 ,local ep 5

COREB: msg type 4000000 index 0 session type 4

COREB: type 4000000, dstep 5, srcep 100

COREB: recved packet msg handle0

COREB: msg_recv_internal msg type 4000000 alloc 3d400c0

COREB: avail 1

COREB: index 0 avail 1

COREB: mcapi_trans_valid_endpoint ep 65541 index 0 valid 1

MCAsm_debug:session status index 0, avail 1

 

 

--- Mingquan Pan                                             2011-09-01 03:56:51

yes, this case can be run stably now and not dump anymore. So close.

 

 

 

    Files

    Changes

    Commits

    Dependencies

    Duplicates

    Associations

    Tags

 

File Name     File Type     File Size     Posted By

No Files Were Found

Attachments

    Outcomes