Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -16,15 +16,20 @@
*/
package org.apache.activemq.artemis.core.protocol.mqtt;

import java.lang.invoke.MethodHandles;

import io.netty.buffer.ByteBufAllocator;
import io.netty.handler.codec.mqtt.MqttConnectMessage;
import io.netty.handler.codec.mqtt.MqttProperties;
import io.netty.handler.codec.mqtt.MqttVersion;
import org.apache.activemq.artemis.api.core.client.ActiveMQClient;
import org.apache.activemq.artemis.core.persistence.impl.journal.ActiveMQIDGeneratorStoppedException;
import org.apache.activemq.artemis.core.server.ActiveMQServer;
import org.apache.activemq.artemis.core.server.ServerSession;
import org.apache.activemq.artemis.core.server.impl.ServerSessionImpl;
import org.apache.activemq.artemis.utils.UUIDGenerator;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import static io.netty.handler.codec.mqtt.MqttProperties.MqttPropertyType.ASSIGNED_CLIENT_IDENTIFIER;
import static io.netty.handler.codec.mqtt.MqttProperties.MqttPropertyType.AUTHENTICATION_METHOD;
Expand All @@ -41,6 +46,8 @@
*/
public class MQTTConnectionManager {

private static final Logger logger = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());

private MQTTSession session;

public MQTTConnectionManager(MQTTSession session) {
Expand Down Expand Up @@ -194,6 +201,8 @@ synchronized void disconnect(boolean failure) {
try {
session.stop(failure);
session.getConnection().destroy();
} catch (ActiveMQIDGeneratorStoppedException ignored) {
logger.debug("Unable to cleanly disconnect MQTT client {} because the storage manager is stopping", session.getState().getClientId(), ignored);
} catch (Exception e) {
MQTTLogger.LOGGER.errorDisconnectingClient(e);
} finally {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@
/**
* Logger Codes 830000 - 839999
*/
@LogBundle(projectCode = "AMQ", regexID = "83[0-9]{4}")
@LogBundle(projectCode = "AMQ", regexID = "83[0-9]{4}", retiredIDs = {834015})
public interface MQTTLogger {

MQTTLogger LOGGER = BundleFactory.newBundle(MQTTLogger.class, MQTTLogger.class.getPackage().getName());
Expand Down Expand Up @@ -77,11 +77,8 @@ public interface MQTTLogger {
@LogMessage(id = 834013, value = "Invalid MQTT session state message. Will not load this state into memory.", level = LogMessage.Level.WARN)
void errorDeserializingStateMessage(Exception e);

@LogMessage(id = 834014, value = "MQTT client {} sent PUBREC for packet {}, but acknowledgement failed. Internal consumer {} not found. Internal session is {}.", level = LogMessage.Level.WARN)
void failedToAckMessageConsumerNotFound(String clientId, int packetId, long consumerId, String closed);

@LogMessage(id = 834015, value = "Unable to handle MQTT packet [{}] from {}. Internal session is closed.", level = LogMessage.Level.ERROR)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if you remove the ID, probably a good idea to retire it?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's been retired. 👍

void internalSessionClosed(String packet, String clientId);
@LogMessage(id = 834014, value = "MQTT client {} sent PUBREC for packet {}, but acknowledgement failed. Internal consumer {} not found.", level = LogMessage.Level.WARN)
void failedToAckMessageConsumerNotFound(String clientId, int packetId, long consumerId);

@LogMessage(id = 834016, value = "Storage operation failed. Error code: {}; message: {}", level = LogMessage.Level.ERROR)
void storageOperationError(int errorCode, String errorMessage);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@
import io.netty.util.CharsetUtil;
import io.netty.util.ReferenceCountUtil;
import org.apache.activemq.artemis.api.core.ActiveMQSecurityException;
import org.apache.activemq.artemis.api.core.ActiveMQShutdownException;
import org.apache.activemq.artemis.api.core.Pair;
import org.apache.activemq.artemis.core.io.IOCallback;
import org.apache.activemq.artemis.core.persistence.OperationContext;
Expand Down Expand Up @@ -126,7 +127,8 @@ public void channelRead(ChannelHandlerContext ctx, Object msg) {
}

if (session.getServerSession() != null && session.getServerSession().isClosed()) {
MQTTLogger.LOGGER.internalSessionClosed(MQTTUtil.getMessageForLogging(message, session.getVersion()), session.getState().getClientId());
// the client sent a packet after its session was closed (e.g. during shutdown or disconnect)
logger.debug("Unable to handle MQTT packet [{}] from {}. Internal session is closed.", MQTTUtil.getMessageForLogging(message, session.getVersion()), session.getState().getClientId());
if (session.getVersion() == MQTTVersion.MQTT_5) {
sendDisconnect(MQTTReasonCodes.IMPLEMENTATION_SPECIFIC_ERROR);
}
Expand Down Expand Up @@ -214,7 +216,11 @@ public void act(MqttMessage message) {
disconnect(true);
}
} catch (Exception e) {
MQTTLogger.LOGGER.errorProcessingPacket(session.getState().getClientId(), MQTTUtil.getMessageForLogging(message, session.getVersion()), e.getMessage(), e);
if (e instanceof ActiveMQShutdownException ignored) {
logger.debug("Unable to process MQTT packet for client {} because the broker is shutting down; packet: {}", session.getState().getClientId(), MQTTUtil.getMessageForLogging(message, session.getVersion()), ignored);
} else {
MQTTLogger.LOGGER.errorProcessingPacket(session.getState().getClientId(), MQTTUtil.getMessageForLogging(message, session.getVersion()), e.getMessage(), e);
}
if (session.getVersion() == MQTTVersion.MQTT_5) {
sendDisconnect(MQTTReasonCodes.IMPLEMENTATION_SPECIFIC_ERROR);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
import org.apache.activemq.artemis.api.core.Message;
import org.apache.activemq.artemis.api.core.RoutingType;
import org.apache.activemq.artemis.api.core.SimpleString;
import org.apache.activemq.artemis.core.persistence.impl.journal.ActiveMQIDGeneratorStoppedException;
import org.apache.activemq.artemis.core.protocol.mqtt.exceptions.DisconnectException;
import org.apache.activemq.artemis.core.server.ServerConsumer;
import org.apache.activemq.artemis.core.server.ServerProducer;
Expand Down Expand Up @@ -338,7 +339,11 @@ private void acknowledgeDelivery(int packetId, boolean needsPubRel) throws Excep
if (delivery != null) {
ServerConsumer consumer = session.getServerSession().locateConsumer(delivery.getConsumerId());
if (consumer == null) {
MQTTLogger.LOGGER.failedToAckMessageConsumerNotFound(state.getClientId(), packetId, delivery.getConsumerId(), session.getServerSession().isClosed() ? "closed" : "not closed");
if (session.getServerSession().isClosed()) {
logger.debug("MQTT client {} sent an acknowledgement for packet {}, but internal consumer {} was not found because the session is closed.", state.getClientId(), packetId, delivery.getConsumerId());
} else {
MQTTLogger.LOGGER.failedToAckMessageConsumerNotFound(state.getClientId(), packetId, delivery.getConsumerId());
}
sendAcknowledgementReply(packetId, MQTTReasonCodes.PACKET_IDENTIFIER_NOT_FOUND, needsPubRel);
return;
}
Expand All @@ -360,7 +365,11 @@ private void acknowledgeDelivery(int packetId, boolean needsPubRel) throws Excep
if (tx != null) {
tx.rollback();
}
MQTTLogger.LOGGER.failedToAckMessage(state.getClientId(), e.getMessage());
if (e instanceof ActiveMQIDGeneratorStoppedException ignored) {
logger.debug("MQTT client {} failed to acknowledge message because the storage manager is stopping", state.getClientId(), ignored);
} else {
MQTTLogger.LOGGER.failedToAckMessage(state.getClientId(), e.getMessage());
}
sendAcknowledgementReply(packetId, MQTTReasonCodes.PACKET_IDENTIFIER_NOT_FOUND, needsPubRel);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,14 +16,21 @@
*/
package org.apache.activemq.artemis.core.protocol.mqtt;

import java.lang.invoke.MethodHandles;

import org.apache.activemq.artemis.api.core.SimpleString;
import org.apache.activemq.artemis.core.persistence.impl.journal.ActiveMQIDGeneratorStoppedException;
import org.apache.activemq.artemis.core.server.MessageReference;
import org.apache.activemq.artemis.core.server.ServerConsumer;
import org.apache.activemq.artemis.spi.core.protocol.SessionCallback;
import org.apache.activemq.artemis.spi.core.remoting.ReadyListener;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MQTTSessionCallback implements SessionCallback {

private static final Logger logger = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());

private final MQTTSession session;
private final MQTTConnection connection;
private final int defaultMaximumInFlightPublishMessages;
Expand All @@ -50,6 +57,8 @@ public int sendMessage(MessageReference ref,
int deliveryCount) {
try {
session.getMqttPublishManager().publishToClient(ref.getMessage().toCore(), consumer);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the right thing would be to make sure these are flushed before. the stop on the MQTPPProtocolManager flushing everything would be a better fix. (the stop is one place it could / should block until things are done).

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm exploring this idea... 🤔

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I looked into what you suggested here and I have a few thoughts:

  1. There is no stop (or equivalent) method for protocol managers. However, it's possible for the protocol manager to register an activation callback and leverage, e.g. org.apache.activemq.artemis.core.server.impl.CleaningActivateCallback#deActivate.
  2. In order to wait for MQTT tasks to finish I now have to track them. This means adding logic to the hot path for all MQTT packet handling rather than just dealing with these exceptions. It is arguably more "correct" to handle shutdown this way, but there is a cost, and I'm not sure that cost is worth paying.

I'd love your thoughts.

} catch (ActiveMQIDGeneratorStoppedException ignored) {
logger.debug("Unable to send message to MQTT client because the storage manager is stopping; consumer: {}; message: {}", consumer, ref, ignored);
} catch (Exception e) {
MQTTLogger.LOGGER.unableToSendMessage(session.getState().getClientId(), ref, e);
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
/*
* Licensed to the Apache Software Foundation (ASF) under one or more
* contributor license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright ownership.
* The ASF licenses this file to You under the Apache License, Version 2.0
* (the "License"); you may not use this file except in compliance with
* the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.apache.activemq.artemis.core.persistence.impl.journal;

/**
* Thrown by an {@link org.apache.activemq.artemis.utils.IDGenerator} when an ID is requested after the generator has
* been stopped.
*/
public class ActiveMQIDGeneratorStoppedException extends RuntimeException {

private static final long serialVersionUID = 8328635365036357836L;

public ActiveMQIDGeneratorStoppedException(String message) {
super(message);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@
import org.apache.activemq.artemis.api.core.SimpleString;
import org.apache.activemq.artemis.api.core.TransportConfiguration;
import org.apache.activemq.artemis.core.io.SequentialFile;
import org.apache.activemq.artemis.core.persistence.impl.journal.ActiveMQIDGeneratorStoppedException;
import org.apache.activemq.artemis.core.postoffice.Binding;
import org.apache.activemq.artemis.core.protocol.core.impl.wireformat.ReplicationSyncFileMessage;
import org.apache.activemq.artemis.core.security.CheckType;
Expand Down Expand Up @@ -533,7 +534,7 @@ IllegalStateException invalidRoutingTypeUpdate(String queueName,
IllegalArgumentException positivePowerOfTwo(String name, Number val);

@Message(id = 229257, value = "IDGenerator has been stopped")
RuntimeException idGeneratorStopped();
ActiveMQIDGeneratorStoppedException idGeneratorStopped();

@Message(id = 229258, value = "Invalid cluster bridge message! No queue IDs defined in the property {}")
ActiveMQIllegalStateException noQueueIdsDefined(SimpleString idsHeaderName);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,11 +16,6 @@
*/
package org.apache.activemq.artemis.tests.unit.core.persistence.impl;

import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertThrowsExactly;
import static org.junit.jupiter.api.Assertions.assertTrue;

import java.io.File;
import java.util.ArrayList;
import java.util.List;
Expand All @@ -33,12 +28,19 @@
import org.apache.activemq.artemis.core.journal.RecordInfo;
import org.apache.activemq.artemis.core.journal.impl.JournalImpl;
import org.apache.activemq.artemis.core.persistence.StorageManager;
import org.apache.activemq.artemis.core.persistence.impl.journal.ActiveMQIDGeneratorStoppedException;
import org.apache.activemq.artemis.core.persistence.impl.journal.BatchingIDGenerator;
import org.apache.activemq.artemis.core.persistence.impl.journal.JournalRecordIds;
import org.apache.activemq.artemis.core.persistence.impl.nullpm.NullStorageManager;
import org.apache.activemq.artemis.tests.util.ActiveMQTestBase;
import org.junit.jupiter.api.Test;

import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertThrows;
import static org.junit.jupiter.api.Assertions.assertThrowsExactly;
import static org.junit.jupiter.api.Assertions.assertTrue;

public class BatchIDGeneratorUnitTest extends ActiveMQTestBase {

@Test
Expand Down Expand Up @@ -120,7 +122,8 @@ public void testSequence() throws Exception {
}

private void validateStoppedGenerator(BatchingIDGenerator stoppedGenerator) {
assertThrowsExactly(RuntimeException.class, stoppedGenerator::generateID);
assertThrowsExactly(ActiveMQIDGeneratorStoppedException.class, stoppedGenerator::generateID);
assertThrows(RuntimeException.class, stoppedGenerator::generateID);
}

protected void loadIDs(final Journal journal, final BatchingIDGenerator batch) throws Exception {
Expand Down
Loading