"Publish was broken by timeout" error after a few publish. Happens only when sending data on multiple topics

[melgo-tb]

I have an application which streams real time financial data when I am trying to publish data on a common topic it is working without any issues, But when I try publishing using a dynamic topic based on the data after a few seconds the publish keeps timing out (30 secs). I am using emqx (4.3) as a broker. The server has 4vCPU and 16GB RAM and resource consumption of emqx is very minimal. Payload size is around 733B

func onTick(tick kitemodels.Tick) {

instr := instrMap[fmt.Sprint(tick.InstrumentToken)]
tickdata := appdata.TickData{   
    Timestamp:          tick.Timestamp,
    LastTradeTime:      tick.LastTradeTime,
    LastPrice:          tick.LastPrice,
    Symbol:             instr,
}

go pubsub.Publish(instr, tickdata)
}

func Publish(topic string, tickdata interface{}) {
    start := time.Now()
    b, err := json.Marshal(tickdata)
    if err != nil {
        fmt.Println(err)
        return
    }
    token := client.Publish(topic, 1, false, b)
    go func() {
        _ = token.Wait()
        if token.Error() != nil {
            fmt.Println("Error While publish", token.Error())
        }
    }()
    elapsed := time.Since(start)
    log.Printf("Publish took %s ", elapsed)
}

Is is something to do with the library configuration? Could someone help me understand what could be the possible reasons for this scenario to occur.

[MattBrittan]

Please see the readme for info to include when raising a bug (currently this is insufficient info to really comment and as it's a question rather than a bug report stack overflow is probably a better place to ask).

In short whether the topic is fixed or dynamic has no real impact on the library (topics are transmitted with every packet so this should not alter the way the library processes requests).

My guess as to the cause of this would be a handler that's blocking (so not related to topics at all).

[melgo-tb]

Hey @MattBrittan thanks for your response, will keep that in mind. I have checked the handler and its not blocking and have checked the sdk logs which looks okay.Must be an issue with the broker configuration.

[MattBrittan]

I cannot think of a situation where the broker configuration would lead to the error you are seeing (this indicates that something is blocking preventing the client from processing the new publish requests). However without more info I can't say what (it's always possible there is a bug).

[melgo-tb]

@MattBrittan

2022-05-12T13:06:07.311875+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:06:07.323874+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:06:12.288160+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:07:12.396988+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:07:48.226856+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:07:53.227733+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: timeout
2022-05-12T13:07:57.436856+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:02.434931+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:07.435589+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: timeout
2022-05-12T13:08:07.457816+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:11.665040+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:12.445891+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:14.510114+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:18.256199+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:23.257714+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: timeout
2022-05-12T13:08:27.431809+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: {shutdown,econnrefused}
2022-05-12T13:08:32.433041+00:00 [error] MzA0ODA0ODYxMTE5MzE2ODQ5Mzc1NDA3NDQ2ODA4OTg1NjA@106.51.65.30:47272 [ACL http] Request ACL path /mqtt/acl, error: timeout

The timeout was occurring from emqx 's ACL path which was setup using mnesia database. The issue does not occur when the messages are sent on the same topic which I guess means the handler is not blocking?

[MattBrittan]

Hard to know without the client logs (I have no experience with emqx so can only guess at the meaning of the logs). It looks like you are publishing to a topic that you do not have access to; the broker should either respond with a puback or drop the connection when that happens.

What I'm guessing is happening here is.

1. You publish on invalid topic
2. Broker disconnects
3. Client reconnects and attempts to resend message

While this loop is going on if you continue to publish messages you may well get the error you are seeing. The client is unable to transmit new requests over this time leading to the issue you see. Note that this guess does depend upon the options used when establishing the connection.

[melgo-tb]

@MattBrittan Resetting the auth settings of the broker seems to have fixed the problem. Thanks for helping out!