Merge pull request #27 from azmigproject/master

Logging applied to more areas

Author: prmathur-microsoft

device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/DeviceClient.java

@@ -86,6 +86,7 @@ protected enum IotHubClientState
     protected ScheduledExecutorService taskScheduler;
     protected IotHubClientState state;
     protected long RECEIVE_PERIOD_MILLIS;
+    protected CustomLogger logger;
 
     /**
      * Constructor that takes a connection string as an argument.
@@ -153,6 +154,8 @@ else if (attr.startsWith(SHARED_ACCESS_TOKEN_ATTRIBUTE))
         }
 
         initIotHubClient(hostname, deviceId, sharedAccessKey, sharedAccessToken, protocol);
+        this.logger = new CustomLogger(this.getClass());
+        logger.LogInfo("DeviceClient object is created successfully, method name is %s ", logger.getMethodName());
     }
 
     /**
@@ -251,6 +254,7 @@ public void sendEventAsync(Message message,
             throw new IllegalArgumentException("Cannot send message 'null'.");
         }
 
+        logger.LogInfo("Message with messageid %s along with callback and callbackcontext is added to the queue, method name is %s ", message.getMessageId(), logger.getMethodName());
         // Codes_SRS_DEVICECLIENT_11_006: [The function shall add the message, with its associated callback and callback context, to the transport.]
         transport.addMessage(message, callback, callbackContext);
     }
@@ -376,6 +380,7 @@ protected DeviceClient()
 
     private void setOption_SetMinimumPollingInterval(Object value)
     {
+        logger.LogInfo("Setting MinimumPollingInterval as %s milliseconds, method name is %s ", value, logger.getMethodName());
         if (!value.equals(null)) {
             if (this.state != IotHubClientState.CLOSED) {
                 throw new IllegalStateException("setOption " + SET_MINIMUM_POLLING_INTERVAL +
@@ -396,6 +401,7 @@ private void setOption_SetMinimumPollingInterval(Object value)
 
     private void setOption_SetCertificatePath(Object value)
     {
+        logger.LogInfo("Setting CertificatePath as %s, method name is %s ", value, logger.getMethodName());
         if (this.state != IotHubClientState.CLOSED) {
             throw new IllegalStateException("setOption " + SET_CERTIFICATE_PATH +
                     "only works when the transport is closed");
@@ -410,6 +416,7 @@ private void setOption_SetCertificatePath(Object value)
 
     private void setOption_SetSASTokenExpiryTime(Object value)
     {
+        logger.LogInfo("Setting SASTokenExpiryTime as %s seconds, method name is %s ", value, logger.getMethodName());
         if (!value.equals(null)) {
             //**Codes_SRS_DEVICECLIENT_25_009: [**"SetSASTokenExpiryTime" should have value type long**.]**
             long validTimeInSeconds;
@@ -502,6 +509,7 @@ public void setOption(String optionName, Object value) {
                         setOption_SetMinimumPollingInterval(value);
 
                     } else {
+                        logger.LogError("optionName is unknown = %s for %s, method name is %s ", optionName, this.transport.getClass(), logger.getMethodName());
                         // Codes_SRS_DEVICECLIENT_02_001: [If optionName is null or not an option
                         // handled by the client, then it shall throw IllegalArgumentException.]
                         throw new IllegalArgumentException("optionName is unknown = " + optionName
@@ -519,6 +527,7 @@ public void setOption(String optionName, Object value) {
                         setOption_SetCertificatePath(value);
 
                     } else {
+                        logger.LogError("optionName is unknown = %s for %s, method name is %s ", optionName, this.transport.getClass(), logger.getMethodName());
                         // Codes_SRS_DEVICECLIENT_02_001: [If optionName is null or not an option handled by the
                         // client, then it shall throw IllegalArgumentException.]
                         throw new IllegalArgumentException("optionName is unknown = " + optionName +
@@ -535,6 +544,7 @@ public void setOption(String optionName, Object value) {
                         setOption_SetSASTokenExpiryTime(value);
 
                     } else {
+                        logger.LogError("optionName is unknown = %s for %s, method name is %s ", optionName, this.transport.getClass(), logger.getMethodName());
                         // Codes_SRS_DEVICECLIENT_02_001: [If optionName is null or not an option handled by the
                         // client, then it shall throw IllegalArgumentException.]
                         throw new IllegalArgumentException("optionName is unknown = " + optionName +

device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/DeviceClientConfig.java

@@ -40,6 +40,7 @@ public final class DeviceClientConfig
     /** The context to be passed in to the message callback. */
     protected Object messageContext;
 
+    protected CustomLogger logger;
     /**
      * Constructor.
      *
@@ -79,7 +80,8 @@ public DeviceClientConfig(String iotHubHostname, String deviceId,
         this.deviceKey = deviceKey;
         // Codes_SRS_DEVICECLIENTCONFIG_25_017: [**The constructor shall save sharedAccessToken.**] **
         this.sharedAccessToken = sharedAccessToken;
-
+        this.logger = new CustomLogger(this.getClass());
+        logger.LogInfo("DeviceClientConfig object is created successfully with IotHubName=%s, deviceID=%s , method name is %s ", this.iotHubName, this.deviceId, logger.getMethodName());
     }
 
     /**

device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/Message.java

@@ -248,6 +248,7 @@ public void setProperty(String name, String value) {
             this.properties.remove(messageProperty);
         }
 
+        logger.LogInfo("Setting message property with name=%s and value=%s, method name is %s ", name, value, logger.getMethodName());
         this.properties.add(new MessageProperty(name, value));
     }
 
@@ -372,6 +373,6 @@ public void setExpiryTime(long timeOut)
     {
         long currentTime = System.currentTimeMillis();
         this.expiryTime = currentTime + timeOut;
-        logger.LogInfo("The message with messageid %s has expiry time as %s, method name is %s ", this.getMessageId(), new Date(this.expiryTime), logger.getMethodName());
+        logger.LogInfo("The message with messageid %s has expiry time as %s milliseconds and the message will expire on %s, method name is %s ", this.getMessageId(), timeOut, new Date(this.expiryTime), logger.getMethodName());
     }
 }

device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/MessageProperty.java

@@ -41,7 +41,7 @@ public final class MessageProperty {
     protected final String name;
     /** The property value. */
     protected final String value;
-
+    protected CustomLogger logger;
     /**
      * Constructor.
      *
@@ -54,29 +54,35 @@ public final class MessageProperty {
      * A message property name cannot be one of the reserved property names.
      */
     public MessageProperty(String name, String value) {
+        this.logger = new CustomLogger(this.getClass());
         if (name == null) {
+            logger.LogError("Property argument 'name' cannot be null, method name is %s ", logger.getMethodName());
             throw new IllegalArgumentException("Property argument 'name' cannot be null.");
         }
 
         if (value == null) {
+            logger.LogError("Property argument 'value' cannot be null, method name is %s ", logger.getMethodName());
             throw new IllegalArgumentException("Property argument 'value' cannot be null.");
         }
 
         // Codes_SRS_MESSAGEPROPERTY_11_002: [If the name contains a character that is not in US-ASCII printable characters or is one of: ()<>@,;:\"/[]?={} (space) (horizontal tab), the function shall throw an IllegalArgumentException.]
         if (!usesValidChars(name)) {
-            String errMsg = String.format("%s is not a valid IoT Hub message property name.\n", name);
+            logger.LogError("%s is not a valid IoT Hub message property name, method name is %s ", name, logger.getMethodName());
+			String errMsg = String.format("%s is not a valid IoT Hub message property name.\n", name);
             throw new IllegalArgumentException(errMsg);
         }
 
         // Codes_SRS_MESSAGEPROPERTY_11_008: [If the name is a reserved property name, the function shall throw an IllegalArgumentException.]
         if (RESERVED_PROPERTY_NAMES.contains(name)) {
-            String errMsg = String.format("%s is a reserved IoT Hub message property name.\n", name);
+            logger.LogError("%s is a reserved IoT Hub message property name, method name is %s ", name, logger.getMethodName());
+			String errMsg = String.format("%s is a reserved IoT Hub message property name.\n", name);
             throw new IllegalArgumentException(errMsg);
         }
 
         // Codes_SRS_MESSAGEPROPERTY_11_003: [If the value contains a character that is not in US-ASCII printable characters or is one of: ()<>@,;:\"/[]?={} (space) (horizontal tab), the function shall throw an IllegalArgumentException.]
         if (!usesValidChars(value))
         {
+            logger.LogError("%s is a reserved IoT Hub message property name, method name is %s ", name, logger.getMethodName());
             String errMsg = String.format("%s is not a valid IoT Hub message property value.\n", value);
             throw new IllegalArgumentException(errMsg);
         }

device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/transport/amqps/AmqpsIotHubConnection.java

@@ -337,11 +337,13 @@ public Integer sendMessage(Message message)
             byte[] msgData = new byte[1024];
             int length;
 
+            logger.LogInfo("Started encoding of message - entering in while loop, method name is %s ", logger.getMethodName());
             while (true)
             {
                 try
                 {
                     length = message.encode(msgData, 0, msgData.length);
+                    logger.LogInfo("Completed encoding of message, length is %s - breaking the while loop to come out, method name is %s ", length, logger.getMethodName());
                     break;
                 }
                 catch (BufferOverflowException e)
@@ -354,15 +356,17 @@ public Integer sendMessage(Message message)
             byte[] tag = String.valueOf(this. nextTag++).getBytes();
             Delivery dlv = sender.delivery(tag);
 
+            logger.LogInfo("Attempting to send the message using the sender link, method name is %s ", logger.getMethodName());
             // Codes_SRS_AMQPSIOTHUBCONNECTION_15_018: [The function shall attempt to send the message using the sender link.]
             sender.send(msgData, 0, length);
-
+            
+            logger.LogInfo("Advancing the sender link, method name is %s ", logger.getMethodName());
             // Codes_SRS_AMQPSIOTHUBCONNECTION_15_019: [The function shall advance the sender link.]
             sender.advance();
 
             // Codes_SRS_AMQPSIOTHUBCONNECTION_15_020: [The function shall set the delivery hash to the value returned by the sender link.]
             deliveryHash = dlv.hashCode();
-            
+            logger.LogInfo("Delivery hash returned by the sender link %s, method name is %s ", deliveryHash, logger.getMethodName());
         }
 
         // Codes_SRS_AMQPSIOTHUBCONNECTION_15_021: [The function shall return the delivery hash.]
@@ -384,6 +388,7 @@ public Boolean sendMessageResult(AmqpsMessage message, IotHubMessageResult resul
         {
             try
             {
+                logger.LogInfo("Acknowledgement for received message is %s, method name is %s ", result.name(), logger.getMethodName());
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_023: [If the message result is COMPLETE, ABANDON, or REJECT,
                 // the function shall acknowledge the last message with acknowledgement type COMPLETE, ABANDON, or REJECT respectively.]
                 switch (result)
@@ -399,6 +404,7 @@ public Boolean sendMessageResult(AmqpsMessage message, IotHubMessageResult resul
                         break;
                     default:
                         // should never happen.
+                        logger.LogError("Invalid IoT Hub message result (%s), method name is %s ", result.name(), logger.getMethodName());
                         throw new IllegalStateException("Invalid IoT Hub message result.");
                 }
 
@@ -545,23 +551,26 @@ public void onDelivery(Event event)
         logger.LogDebug("Entered in method %s", logger.getMethodName());
         if(event.getLink().getName().equals(receiveTag))
         {
+            logger.LogInfo("Reading the receiver link, method name is %s ", logger.getMethodName());
             // Codes_SRS_AMQPSIOTHUBCONNECTION_15_034: [If this link is the Receiver link, the event handler shall get the Receiver and Delivery (Proton) objects from the event.]
             Receiver receiveLink = (Receiver) event.getLink();
             Delivery delivery = receiveLink.current();
             if (delivery.isReadable() && !delivery.isPartial()) {
+                logger.LogInfo("Reading the received buffer, method name is %s ", logger.getMethodName());
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_035: [The event handler shall read the received buffer.]
                 int size = delivery.pending();
                 byte[] buffer = new byte[size];
                 int read = receiveLink.recv(buffer, 0, buffer.length);
                 receiveLink.advance();
-
+                logger.LogInfo("Reading the received buffer completed, method name is %s ", logger.getMethodName());
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_036: [The event handler shall create an AmqpsMessage object from the decoded buffer.]
                 AmqpsMessage msg = new AmqpsMessage();
 
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_037: [The event handler shall set the AmqpsMessage Deliver (Proton) object.]
                 msg.setDelivery(delivery);
+                logger.LogInfo("Decoding the received message , method name is %s ", logger.getMethodName());
                 msg.decode(buffer, 0, read);
-
+                logger.LogInfo("Decoding the received message completed , method name is %s ", logger.getMethodName());
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_049: [All the listeners shall be notified that a message was received from the server.]
                 this.messageReceivedFromServer(msg);
             }
@@ -571,12 +580,15 @@ public void onDelivery(Event event)
             //Sender specific section for dispositions it receives
             if(event.getType() == Event.Type.DELIVERY)
             {
+                logger.LogInfo("Reading the delivery event in Sender link, method name is %s ", logger.getMethodName());
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_038: [If this link is the Sender link and the event type is DELIVERY, the event handler shall get the Delivery (Proton) object from the event.]
                 Delivery d = event.getDelivery();
                 DeliveryState remoteState = d.getRemoteState();
 
                 // Codes_SRS_AMQPSIOTHUBCONNECTION_15_039: [The event handler shall note the remote delivery state and use it and the Delivery (Proton) hash code to inform the AmqpsIotHubConnection of the message receipt.]
                 boolean state = remoteState.equals(Accepted.getInstance());
+                logger.LogInfo("Is state of remote Delivery COMPLETE ? %s, method name is %s ", state, logger.getMethodName());
+                logger.LogInfo("Inform listener that a message has been sent to IoT Hub along with remote state, method name is %s ", logger.getMethodName());
                 //let any listener know that the message was received by the server
                 for(ServerListener listener : listeners)
                 {
@@ -597,6 +609,7 @@ public void onLinkFlow(Event event)
         logger.LogDebug("Entered in method %s", logger.getMethodName());
         // Codes_SRS_AMQPSIOTHUBCONNECTION_15_040: [The event handler shall save the remaining link credit.]
         this.linkCredit = event.getLink().getCredit();
+		logger.LogDebug("The link credit value is %s, method name is %s", this.linkCredit, logger.getMethodName());
         logger.LogDebug("Exited from method %s", logger.getMethodName());
     }
 
@@ -732,6 +745,7 @@ private void startReconnect()
      */
     private void messageReceivedFromServer(AmqpsMessage msg)
     {
+        logger.LogInfo("All the listeners are informed that a message has been received, method name is %s ", logger.getMethodName());
         for(ServerListener listener : listeners)
         {
             listener.messageReceived(msg);