HEVC encoder without tiles hangs on multiple DSPs

Hi Andrey Lisnevich,

I am working on it.

Thanks and Regards,
Palachandra M V

Hi Andrey,

1. I am able to run the demo application using CCS.

2. When I tried encoding the stream using 2 chips with tiles disabled, starting few frames are encoded before it hangs.

3. When I tried to debug the cause of hang
- Master is in ti_sysbios_hal_Hwi_HwiProxy_getStackInfo__E module.
- Slave core stuck in doSlaveEncoding module as the codition (value != nextIterationId - 1) always equal to 0. (that is value is always equal to (nextIterationId - 1))

4. It looks like hang is observed in test application.

5. When I tried encoding the stream without ccs by making the changes as in README.txt, codec fails in intialization

$ ./hevc_demo 2
Open DSP & CMEM driver
Initializing DSP#0

5. Can you please give me your feedback on my findings.

Thanks and Regards,
Palachandra M V
www.pathpartnertech.com

Hi Andrey Lisnevich,

I am able to reproduce the issue. When encoder hangs, chip0 task completion status is not reflected in chip1, It looks like on writing to mailbox either Interrupt may not have been generated by chip0  or chip1 may have missed the Interrupt. Working on the same.

Thanks and Regards,
Palachandra M V

Hi Andrey Lisnevich,

I tried to debug the hang issue, please find my finding below

1. Instead of Interrupt if polling is used to update the task completion status, codec runs without hang.
2. When encoder hang is observed, chip0 task completion status is not updated in chip1
3. On task completion, chip0 update the status through the mailbox and conveys the same to chip1 by triggering an interrupt.
4. On receiving the interrupt, chip1 update the status by executing ISR.
5. We verified that mailboxwrite is happening in chip0 and same status is reflected in chip1.
6. chip1 is not intimated regarding mailboxwrite by chip0 through interrupt. Hence chip1 is waiting for the interrupt to execute ISR.
7. In MCSDK (file : siuVidMc3.c), whenever an interrupt is raised by chip0, content at address IPCGR_BASE is set, on executing of ISR by chip1 the content at address IPCGR_BASE bit is reset.
8. In hevc_demo application I need to verify the contents of IPCGR_BASE when hang is observed.
9. If contents of IPCGR_BASE is set it indicates chip0 has triggered interrupt and chip1 has not received and if contents of IPCGR_BASE is not set then it indicates chip1 may not have triggered interrupt or there may be delay in mailboxwrite.
10. Can you please let me know on how interrupt is configured and triggered by chip0 and how the same is received by chip1 in hevc_demo application.

Thanks and Regards,
Palachandra M V
www.pathpartnertech.com

Hi Andrey Lisnevich,

Can you please provide an update on my findings.

Thanks and Regards,
Palachandra M V
www.pathpartnertech.com

Hi Palachandra,

The issue is still not resolved. Really one of mailbox messages isn't read on receiver DSP. I still do investigation.

Regards,

Andrey Lisnevich

Hi Andrey,

Can you please let me know that if you are still facing the issue.

Thanks and Regards,

Palachandra M V

Hi Palachandra,

Really there were problems with cross  DSP interrupts generation. Not all generated interrupts were called on receiving DSP. I fixed it but for 2 DSP mode only currently. Please update 2 attached files to fix:

/**
 * Codec interrupt API
 */

#include "CodecIsr.h"

#include "IpcInterrupt.h"
#include "Configuration.h"
#include "DspUtils.h"
#include "GlobalGates.h"

#include <ti/csl/cslr_ipc.h>
#include <ti/csl/cslr_device.h>

#include <assert.h>

extern cregister volatile unsigned int DNUM;

#define CODEC_COMMAND          (IPCI_COMMAND0)
#define CODEC_IPC_CORE         (0)
#define GET_IPC_REGS(a)        ((CSL_IPCRegs *) (a + 0x200))

typedef struct {
    void* handle;
    CodecIsrCallback isrCallback;
} CodecIsrContext;

static CodecIsrContext codecIsrContext;

static CSL_IPCRegs* dspIpc[MAX_DSP_IN_GROUP];

static inline Uint32 Codec_IPC_isGEMInterruptSourceSet(CSL_IPCRegs* hIpc, Uint32 index, Uint32 srcId)
{
    return CSL_FEXTR(hIpc->IPCGR[index], CSL_IPC_IPCGR_SRCS0_SHIFT + srcId, CSL_IPC_IPCGR_SRCS0_SHIFT + srcId);
}

static inline void Codec_IPC_genGEMInterrupt(CSL_IPCRegs* hIpc, Uint32 index, Uint32 srcId)
{
    hIpc->IPCGR[index]  =   CSL_FMK (IPC_IPCGR_IPCG, 1) |
                            CSL_FMKR (CSL_IPC_IPCGR_SRCS0_SHIFT + srcId, CSL_IPC_IPCGR_SRCS0_SHIFT + srcId, 1);
}

static void codecIsrHandler()
{
    if (codecIsrContext.isrCallback != NULL) {
        codecIsrContext.isrCallback(codecIsrContext.handle);
    }
}

ResultCode CodecIsr_init()
{
    uint32_t i;
    int outboundDspId;

    const DspConfiguration* configuration = Configuration_get();
    unsigned int localDspId = DspUtils_getGroupDspId();

    for (outboundDspId = 0; outboundDspId < DspUtils_getDspGroupSize(); outboundDspId++) {
        for (i = 0; i < configuration->ipcregMappedRegionsCount; i++) {
            if (outboundDspId == localDspId) {
                dspIpc[outboundDspId] = GET_IPC_REGS(CSL_BOOT_CFG_REGS);
                break;
            }

            if ((configuration->ipcregMappedRegions[i].localDspId == outboundDspId) &&
                (configuration->ipcregMappedRegions[i].outboundDspId == localDspId)) {
                dspIpc[outboundDspId] = GET_IPC_REGS(configuration->ipcregMappedRegions[i].outboundAddress);
                break;
            }
        }
    }

    if (DNUM == 0) {
        IpcInterrupt_setCommandCallback(CODEC_COMMAND, codecIsrHandler);
    }

    return ResultCode_Ok;
}

void CodecIsr_generate(uint32_t dspId)
{
    assert(dspId < DspUtils_getDspGroupSize());

    CSL_IPCRegs* hIpc = dspIpc[dspId];

    if (hIpc != NULL) {
        //IArg gateKey = GateMP_enter(GlobalGates_getIpcInterruptGate());

        while (Codec_IPC_isGEMInterruptSourceSet(hIpc, CODEC_IPC_CORE, IpcInterrupt_getCommandCode(CODEC_COMMAND)));
        Codec_IPC_genGEMInterrupt(hIpc, CODEC_IPC_CORE, IpcInterrupt_getCommandCode(CODEC_COMMAND));

        //GateMP_leave(GlobalGates_getIpcInterruptGate(), gateKey);
    }
}

void CodecIsr_set(CodecIsrCallback callback, void* handle)
{
    assert(callback != NULL);
    assert(handle != NULL);

    codecIsrContext.handle = handle;
    codecIsrContext.isrCallback = callback;
}

void CodecIsr_reset()
{
    codecIsrContext.handle = NULL;
    codecIsrContext.isrCallback = NULL;
}

/**
 * IPC interrupt API
 */

#include <xdc/runtime/System.h>
#include <xdc/runtime/Error.h>
#include <ti/sysbios/hal/Hwi.h>

#include <ti/csl/cslr_device.h>
#include <ti/csl/csl_ipcAux.h>

#include "IpcInterrupt.h"
#include "GlobalGates.h"

#include <assert.h>

extern cregister volatile unsigned int DNUM;

#define IPCI_INTC     (6)
#define IPCI_EVENT    (CSL_GEM_IPC_LOCAL)

#define IPCI_COMMAND_BASE (20)
#define IPCI_MAX_COMMANDS (4)

static IpcInterruptCallback commandHandlers[IPCI_MAX_COMMANDS];

static void commandIsr(xdc_UArg args)
{
    unsigned int command;
    for (command = 0; command < IPCI_MAX_COMMANDS; command++) {
        if (CSL_IPC_isGEMInterruptSourceSet(DNUM, IpcInterrupt_getCommandCode(command))) {
            CSL_IPC_clearGEMInterruptSource(DNUM, IpcInterrupt_getCommandCode(command));
            if (commandHandlers[command] != NULL) {
                commandHandlers[command]();
            }
        }
    }
}

ResultCode IpcInterrupt_init()
{
    Hwi_Params hwiParams;
    Error_Block eb;

    Hwi_Params_init(&hwiParams);
    Error_init(&eb);

    hwiParams.eventId = IPCI_EVENT;
    hwiParams.enableInt = 1;

    Hwi_Handle ipciHwi = Hwi_create(IPCI_INTC, commandIsr, &hwiParams, &eb);

    if (Error_check(&eb)) {
        return ResultCode_Error;
    }

    return ResultCode_Ok;
}

void IpcInterrupt_setCommandCallback(int32_t command, IpcInterruptCallback callback)
{
    assert(command < IPCI_MAX_COMMANDS);
    commandHandlers[command] = callback;
}

void IpcInterrupt_triggerCommand(int32_t core, int32_t command)
{
    assert(command < IPCI_MAX_COMMANDS);
    assert(core < CORES_PER_DSP);

    IArg gateKey = GateMP_enter(GlobalGates_getIpcInterruptGate());

    while (CSL_IPC_isGEMInterruptSourceSet(core, IpcInterrupt_getCommandCode(command)));
    CSL_IPC_genGEMInterrupt(core, IpcInterrupt_getCommandCode(command));

    GateMP_leave(GlobalGates_getIpcInterruptGate(), gateKey);
}

void IpcInterrupt_triggerCommandOnCores(const int32_t* coreIds, int32_t command)
{
    assert(command < IPCI_MAX_COMMANDS);

    IArg gateKey = GateMP_enter(GlobalGates_getIpcInterruptGate());

    int i = 0;
    for (i = 0; i < CORES_PER_DSP; i++) {
        if (coreIds[i] == -1) {
            break;
        }

        assert(coreIds[i] < CORES_PER_DSP);

        while (CSL_IPC_isGEMInterruptSourceSet(coreIds[i], IpcInterrupt_getCommandCode(command)));
        CSL_IPC_genGEMInterrupt(coreIds[i], IpcInterrupt_getCommandCode(command));
    }

    GateMP_leave(GlobalGates_getIpcInterruptGate(), gateKey);
}

uint32_t IpcInterrupt_getCommandCode(uint32_t command) {
    return IPCI_COMMAND_BASE + command;
}

But demo still has problems -  it crashes with time with message:

Process BEGIN

Process END

Process BEGIN

Process END

Process BEGIN

[t=0x00000036:8f94f4b2] ti.sysbios.gates.GateMutex: ERROR: line 97: assertion failure: A_badContext: bad calling context. See GateMutex API doc for details.

ti.sysbios.gates.GateMutex: line 97: assertion failure: A_badContext: bad calling context. See GateMutex API doc for details.

xdc.runtime.Error.raise: terminating execution

Full log: console-0-0.log

1) It crashes inside HEVC's encoder process call

2) I use GateMP API only in Lock API callbacks implementation but I debugged and know that the crash isn't in there.

Can you help to find out why does it happen?

3) It is not crashing when tiles are enabled.

Please use only 2 DSP mode for tests.

Regards,

Andrey Lisnevich

Hi Andrey,

I tried running the HEVC with your fix, Observed hang when run without ccs hang is random. When run with ccs did not observed hang. Will try to reproduce the hang in ccs. 

Thanks and Regards,
Palachandra M V

Hi Andrey,

1. Considering above changes provided for the code base, we did not observe any assertion error.

2. Codec hang is still observed with changes you provided and we still feel its an interrupt issue as we had suspected earlier.

3. HEVC encoder library with polling enabled is attached. With this library we did not observe any hang where as it used to hang when interrupts were being used. Can you please check this library at your end. This library is for testing only as this may result in slight drop in performance.

5736.lib.7z

Regards,

Mashkur

Hi Mashkur,

With the given library encoder doesn't hang. Also as I see this library still uses mailboxes so problem not in mailboxes IO. So really it looks like problem in interrupts.

But I did debugging. I calculate number of sent interrupts and number of received interrupts and it matches for both DSP#0->DSP#1 and DSP#1->DSP#0.

What I see is at some point encoders stops calling Mailbox API in interrupt handler that leads to hang.

Full logs are attached. What you can see from logs:

hevc_logs.zip

1) It hanged in process call

2) At the end of the log independent ISR counters on DSP#0 and DSP#1 shows that all the interupts were received:

DSP#0:

[2016-01-15 21:54:31] ISR IN C1 776168

[2016-01-15 21:54:31] ISR OUT C1 846732

DSP#1:

[2016-01-15 21:54:31] ISR IN C1 846732

[2016-01-15 21:54:31] ISR OUT C1 776168

3) IDs and hashes of last input and output messages say that DSP#1 stopped to read messages. Last read message was 846719. At the same time last sent message was 846731. On DSP#0 all the messages were read:

DSP#0:

[2016-01-15 21:54:31] OUT MESSAGES:

[2016-01-15 21:54:31] 846730 8 1620345916

[2016-01-15 21:54:31] 846731 8 3115619984

[2016-01-15 21:54:31] IN MESSAGES:

[2016-01-15 21:54:31] 776160 8 2985851136

[2016-01-15 21:54:31] 776161 8 3347464498

[2016-01-15 21:54:31] 776162 8 1552110819

[2016-01-15 21:54:31] 776163 8 2216958920

[2016-01-15 21:54:31] 776164 8 2961122439

[2016-01-15 21:54:31] 776165 8 1767847467

[2016-01-15 21:54:31] 776166 8 2381294047

[2016-01-15 21:54:31] 776167 8 2889778338

DSP#1:

[2016-01-15 21:54:31] OUT MESSAGES:

[2016-01-15 21:54:31] 776160 8 2985851136

[2016-01-15 21:54:31] 776161 8 3347464498

[2016-01-15 21:54:31] 776162 8 1552110819

[2016-01-15 21:54:31] 776163 8 2216958920

[2016-01-15 21:54:31] 776164 8 2961122439

[2016-01-15 21:54:31] 776165 8 1767847467

[2016-01-15 21:54:31] 776166 8 2381294047

[2016-01-15 21:54:31] 776167 8 2889778338

[2016-01-15 21:54:31] IN MESSAGES:

[2016-01-15 21:54:31] 846710 8 714580450

[2016-01-15 21:54:31] 846711 8 1620345916

[2016-01-15 21:54:31] 846712 8 3685559332

[2016-01-15 21:54:31] 846713 8 4249074821

[2016-01-15 21:54:31] 846714 8 1464497166

[2016-01-15 21:54:31] 846715 8 4025881451

[2016-01-15 21:54:31] 846716 8 3115619984

[2016-01-15 21:54:31] 846717 8 610512425

[2016-01-15 21:54:31] 846718 8 2389337762

[2016-01-15 21:54:31] 846719 8 919994823

4) At some point DSP#1 stopped to read messages in interrupt handler. It just do not call mailbox read api at all and I don't know why it is so:

[2016-01-15 21:54:24] PROCESS BEGIN

[2016-01-15 21:54:24] PROCESS END

[2016-01-15 21:54:24] PROCESS BEGIN

[2016-01-15 21:54:24] >>> ERR4: multiple reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] PROCESS END

[2016-01-15 21:54:24] PROCESS BEGIN

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] >>> ERR3: no reads

"no reads" means that there is no mailbox reads calls in interrupt handler.

"multiple reads" means that interrupt handler read more than 1 message.

When interrupt handler read exactly 1 message I do not output anything to make log smaller.

Usually "multiple reads" and "no reads" go in pair. It means that two messages were sent almost at the same time and both were read in first interrupt handler. and that is why no messages read while next interrupt handler :

[2016-01-15 21:54:24] >>> ERR4: multiple reads

[2016-01-15 21:54:24] >>> ERR3: no reads

Can you comment above? Do you see any problems?

Regards,

Andrey Lisnevich

Hi Andrey,

I observed following points in your code base and logs.

1.It looks like you are restricting maxMails to 1000 by a check condition in createMailboxKey and attachMailboxKey functions in TranscodeComponent.c.

int maxMails = (cfg->u.mailBox.max_mails > 1000) ? 1000 : cfg->u.mailBox.max_mails;

Can you please remove this condition and try running Because there is a chance of msg overflow in mailbox. Let me know whether it hangs or not.

2. I observed in  DSP#1 log(console-1-0.log) that interrput number 776079 is missing in OUT messages as ISR OUT C1 is 776080. This is occuring 3 processes before hang is observed.

[2016-01-15 21:54:24] PROCESS BEGIN

[2016-01-15 21:54:24] >>> ERR4: multiple reads

[2016-01-15 21:54:24] >>> ERR3: no reads

[2016-01-15 21:54:24] OUT MESSAGES:

[2016-01-15 21:54:24] 776070 8 1765145368

[2016-01-15 21:54:24] 776071 8 2381294047

[2016-01-15 21:54:24] 776072 8 4032344320

[2016-01-15 21:54:24] 776073 8 2889778338

[2016-01-15 21:54:24] 776074 8 3243535450

[2016-01-15 21:54:24] 776075 8 1801299153

[2016-01-15 21:54:24] 776076 8 3434010783

[2016-01-15 21:54:24] 776077 8 435364721

[2016-01-15 21:54:24] 776078 8 3019566074

[2016-01-15 21:54:24] 776069 8 1515288971

[2016-01-15 21:54:24] IN MESSAGES:

[2016-01-15 21:54:24] 846620 8 2219759355

[2016-01-15 21:54:24] 846621 8 3415303491

[2016-01-15 21:54:24] 846622 8 1637395912

[2016-01-15 21:54:24] 846623 8 1217272662

[2016-01-15 21:54:24] 846624 8 3579388911

[2016-01-15 21:54:24] 846625 8 1055925092

[2016-01-15 21:54:24] 846626 8 2136009572

[2016-01-15 21:54:24] 846627 8 2737249245

[2016-01-15 21:54:24] 846628 8 3643067053

[2016-01-15 21:54:24] 846629 8 154063702

[2016-01-15 21:54:24] MB IN @85003a80 EMPTY

[2016-01-15 21:54:24] MB OUT @85003980

[2016-01-15 21:54:24] MB OUT @85003900

[2016-01-15 21:54:24] ISR IN C1 846630

[2016-01-15 21:54:24] ISR IN C2 0

[2016-01-15 21:54:24] ISR OUT C1 776080

[2016-01-15 21:54:24] ISR OUT C2 776080

[2016-01-15 21:54:24] PROCESS END

3. I see a macro MAX_IVIDMC3_MAILBOXES equal to 32 in TranscodeComponent.c. Can you please let me know why it is used?

Regards,

Mashkur

Hi Andrey,

My findings are as follows.

1. In our dsp application, after mailbox_write IPCGR register is set and before mailbox_read IPCAR register is reset. In your application IPCGR is getting set after mailbox_write but IPCAR is not reset before mailbox_read. For your reference I have attached implementation of mailbox_read and mailbox_write in both our application in the zip file below. Can you please let me know

i)what is the reason for it and

ii) how you are managing interrupts and mailbox reads and writes.

2. Assertion failure occurs if you are using printf or gateMutex inside SWI. Please refer below thread for more info.

https://e2e.ti.com/support/embedded/tirtos/f/355/t/376920

2133.New folder.7z

Regards,

Mashkur

Hi Andrey,

Any update on the issue?

Regards,

Mashkur

Hi Andrey,

Can you please update me on the issue?

Regards,
Mashkur

Hi Andrey,

This thread has been active for a long time. The thread won't be considered as closed until it is marked as answered. Pleas mark it as answered and create new thread for other issues.

Thanks and Regards,

Mashkur