Enhance the debug output for StateMachines.
Allow some messages to be ignored and allow the subclass to
add additional information. In particular, the information
can be used to decode the msg.what to a string.
Change-Id: I4f53becc6f0cb77399f99702084efef9d8785d67
diff --git a/core/java/com/android/internal/util/AsyncChannel.java b/core/java/com/android/internal/util/AsyncChannel.java
index 3973344..0c5d5ef 100644
--- a/core/java/com/android/internal/util/AsyncChannel.java
+++ b/core/java/com/android/internal/util/AsyncChannel.java
@@ -150,6 +150,24 @@
*/
public static final int CMD_CHANNEL_DISCONNECTED = BASE + 4;
+ private static final int CMD_TO_STRING_COUNT = CMD_CHANNEL_DISCONNECTED + 1;
+ private static String[] sCmdToString = new String[CMD_TO_STRING_COUNT];
+ static {
+ sCmdToString[CMD_CHANNEL_HALF_CONNECTED - BASE] = "CMD_CHANNEL_HALF_CONNECTED";
+ sCmdToString[CMD_CHANNEL_FULL_CONNECTION - BASE] = "CMD_CHANNEL_FULL_CONNECTION";
+ sCmdToString[CMD_CHANNEL_FULLY_CONNECTED - BASE] = "CMD_CHANNEL_FULLY_CONNECTED";
+ sCmdToString[CMD_CHANNEL_DISCONNECT - BASE] = "CMD_CHANNEL_DISCONNECT";
+ sCmdToString[CMD_CHANNEL_DISCONNECTED - BASE] = "CMD_CHANNEL_DISCONNECTED";
+ }
+ protected static String cmdToString(int cmd) {
+ cmd -= BASE;
+ if ((cmd >= 0) && (cmd < sCmdToString.length)) {
+ return sCmdToString[cmd];
+ } else {
+ return null;
+ }
+ }
+
/** Successful status always 0, !0 is an unsuccessful status */
public static final int STATUS_SUCCESSFUL = 0;
diff --git a/core/java/com/android/internal/util/StateMachine.java b/core/java/com/android/internal/util/StateMachine.java
index 07496a7..1391ac3 100644
--- a/core/java/com/android/internal/util/StateMachine.java
+++ b/core/java/com/android/internal/util/StateMachine.java
@@ -20,9 +20,13 @@
import android.os.HandlerThread;
import android.os.Looper;
import android.os.Message;
+import android.text.TextUtils;
import android.util.Log;
+import java.io.FileDescriptor;
+import java.io.PrintWriter;
import java.util.ArrayList;
+import java.util.Calendar;
import java.util.HashMap;
import java.util.Vector;
@@ -444,9 +448,11 @@
* The information maintained for a processed message.
*/
public static class ProcessedMessageInfo {
- private int what;
- private State state;
- private State orgState;
+ private long mTime;
+ private int mWhat;
+ private String mInfo;
+ private State mState;
+ private State mOrgState;
/**
* Constructor
@@ -455,8 +461,8 @@
* @param orgState is the first state the received the message but
* did not processes the message.
*/
- ProcessedMessageInfo(Message message, State state, State orgState) {
- update(message, state, orgState);
+ ProcessedMessageInfo(Message msg, String info, State state, State orgState) {
+ update(msg, info, state, orgState);
}
/**
@@ -465,31 +471,47 @@
* @param orgState is the first state the received the message but
* did not processes the message.
*/
- public void update(Message message, State state, State orgState) {
- this.what = message.what;
- this.state = state;
- this.orgState = orgState;
+ public void update(Message msg, String info, State state, State orgState) {
+ mTime = System.currentTimeMillis();
+ mWhat = msg.what;
+ mInfo = info;
+ mState = state;
+ mOrgState = orgState;
+ }
+
+ /**
+ * @return time stamp
+ */
+ public long getTime() {
+ return mTime;
+ }
+
+ /**
+ * @return msg.what
+ */
+ public long getWhat() {
+ return mWhat;
}
/**
* @return the command that was executing
*/
- public int getWhat() {
- return what;
+ public String getInfo() {
+ return mInfo;
}
/**
* @return the state that handled this message
*/
public State getState() {
- return state;
+ return mState;
}
/**
* @return the original state that received the message.
*/
public State getOriginalState() {
- return orgState;
+ return mOrgState;
}
/**
@@ -498,26 +520,24 @@
@Override
public String toString() {
StringBuilder sb = new StringBuilder();
- sb.append("what=");
- sb.append(what);
+ sb.append("time=");
+ Calendar c = Calendar.getInstance();
+ c.setTimeInMillis(mTime);
+ sb.append(String.format("%tm-%td %tH:%tM:%tS.%tL", c, c, c, c, c, c));
sb.append(" state=");
- sb.append(cn(state));
+ sb.append(mState == null ? "<null>" : mState.getName());
sb.append(" orgState=");
- sb.append(cn(orgState));
- return sb.toString();
- }
-
- /**
- * @return an objects class name
- */
- private String cn(Object n) {
- if (n == null) {
- return "null";
- } else {
- String name = n.getClass().getName();
- int lastDollar = name.lastIndexOf('$');
- return name.substring(lastDollar + 1);
+ sb.append(mOrgState == null ? "<null>" : mOrgState.getName());
+ sb.append(" what=");
+ sb.append(mWhat);
+ sb.append("(0x");
+ sb.append(Integer.toHexString(mWhat));
+ sb.append(")");
+ if ( ! TextUtils.isEmpty(mInfo)) {
+ sb.append(" ");
+ sb.append(mInfo);
}
+ return sb.toString();
}
}
@@ -542,9 +562,9 @@
private int mCount = 0;
/**
- * Constructor
+ * private constructor use add
*/
- ProcessedMessages() {
+ private ProcessedMessages() {
}
/**
@@ -599,22 +619,23 @@
/**
* Add a processed message.
*
- * @param message
+ * @param msg
+ * @param messageInfo to be stored
* @param state that handled the message
* @param orgState is the first state the received the message but
* did not processes the message.
*/
- void add(Message message, State state, State orgState) {
+ void add(Message msg, String messageInfo, State state, State orgState) {
mCount += 1;
if (mMessages.size() < mMaxSize) {
- mMessages.add(new ProcessedMessageInfo(message, state, orgState));
+ mMessages.add(new ProcessedMessageInfo(msg, messageInfo, state, orgState));
} else {
ProcessedMessageInfo pmi = mMessages.get(mOldestIndex);
mOldestIndex += 1;
if (mOldestIndex >= mMaxSize) {
mOldestIndex = 0;
}
- pmi.update(message, state, orgState);
+ pmi.update(msg, messageInfo, state, orgState);
}
}
}
@@ -894,11 +915,14 @@
/**
* Record that we processed the message
*/
- if (curStateInfo != null) {
- State orgState = mStateStack[mStateStackTopIndex].state;
- mProcessedMessages.add(msg, curStateInfo.state, orgState);
- } else {
- mProcessedMessages.add(msg, null, null);
+ if (mSm.recordProcessedMessage(msg)) {
+ if (curStateInfo != null) {
+ State orgState = mStateStack[mStateStackTopIndex].state;
+ mProcessedMessages.add(msg, mSm.getMessageInfo(msg), curStateInfo.state,
+ orgState);
+ } else {
+ mProcessedMessages.add(msg, mSm.getMessageInfo(msg), null, null);
+ }
}
}
@@ -1546,6 +1570,24 @@
}
/**
+ * @return true if msg should be saved in ProcessedMessage, default is true.
+ */
+ protected boolean recordProcessedMessage(Message msg) {
+ return true;
+ }
+
+ /**
+ * Return message info to be logged by ProcessedMessageInfo, default
+ * is an empty string. Override if additional information is desired.
+ *
+ * @param msg that was processed
+ * @return information to be logged as a String
+ */
+ protected String getMessageInfo(Message msg) {
+ return "";
+ }
+
+ /**
* @return if debugging is enabled
*/
public boolean isDbg() {
@@ -1577,4 +1619,21 @@
/** Send the complete construction message */
mSmHandler.completeConstruction();
}
+
+ /**
+ * Dump the current state.
+ *
+ * @param fd
+ * @param pw
+ * @param args
+ */
+ public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
+ pw.println(getName() + ":");
+ pw.println(" total messages=" + getProcessedMessagesCount());
+ for (int i=0; i < getProcessedMessagesSize(); i++) {
+ pw.printf(" msg[%d]: %s\n", i, getProcessedMessageInfo(i));
+ pw.flush();
+ }
+ pw.println("curState=" + getCurrentState().getName());
+ }
}
diff --git a/telephony/java/com/android/internal/telephony/DataConnection.java b/telephony/java/com/android/internal/telephony/DataConnection.java
index 486a924..a124c7f 100644
--- a/telephony/java/com/android/internal/telephony/DataConnection.java
+++ b/telephony/java/com/android/internal/telephony/DataConnection.java
@@ -35,6 +35,7 @@
import java.io.FileDescriptor;
import java.io.PrintWriter;
import java.util.ArrayList;
+import java.util.Calendar;
import java.util.HashMap;
import java.util.List;
@@ -208,6 +209,27 @@
protected static final int EVENT_RIL_CONNECTED = BASE + 5;
protected static final int EVENT_DISCONNECT_ALL = BASE + 6;
+ private static final int CMD_TO_STRING_COUNT = EVENT_DISCONNECT_ALL + 1;
+ private static String[] sCmdToString = new String[CMD_TO_STRING_COUNT];
+ static {
+ sCmdToString[EVENT_CONNECT - BASE] = "EVENT_CONNECT";
+ sCmdToString[EVENT_SETUP_DATA_CONNECTION_DONE - BASE] =
+ "EVENT_SETUP_DATA_CONNECTION_DONE";
+ sCmdToString[EVENT_GET_LAST_FAIL_DONE - BASE] = "EVENT_GET_LAST_FAIL_DONE";
+ sCmdToString[EVENT_DEACTIVATE_DONE - BASE] = "EVENT_DEACTIVATE_DONE";
+ sCmdToString[EVENT_DISCONNECT - BASE] = "EVENT_DISCONNECT";
+ sCmdToString[EVENT_RIL_CONNECTED - BASE] = "EVENT_RIL_CONNECTED";
+ sCmdToString[EVENT_DISCONNECT_ALL - BASE] = "EVENT_DISCONNECT_ALL";
+ }
+ protected static String cmdToString(int cmd) {
+ cmd -= BASE;
+ if ((cmd >= 0) && (cmd < sCmdToString.length)) {
+ return sCmdToString[cmd];
+ } else {
+ return null;
+ }
+ }
+
//***** Tag IDs for EventLog
protected static final int EVENT_LOG_BAD_DNS_ADDRESS = 50100;
@@ -242,6 +264,7 @@
protected DataConnection(PhoneBase phone, String name, int id, RetryManager rm,
DataConnectionTracker dct) {
super(name);
+ setProcessedMessagesSize(100);
if (DBG) log("DataConnection constructor E");
this.phone = phone;
this.mDataConnectionTracker = dct;
@@ -1188,26 +1211,65 @@
new DisconnectParams(reason, onCompletedMsg)));
}
+ /**
+ * @return the string for msg.what as our info.
+ */
+ @Override
+ protected String getMessageInfo(Message msg) {
+ String info = null;
+ info = cmdToString(msg.what);
+ if (info == null) {
+ info = DataConnectionAc.cmdToString(msg.what);
+ }
+ return info;
+ }
+
+ /**
+ * Convert a System.currentTimeMillis() value to a time of day value.
+ *
+ * @param millis since the epoch (1/1/1970)
+ * @return String representation of the time.
+ */
+ private String timeMillisToTimeOfDay(long millis) {
+ Calendar c = Calendar.getInstance();
+ if (millis >= 0) {
+ c.setTimeInMillis(millis);
+ return String.format("%tm-%td %tH:%tM:%tS.%tL", c, c, c, c, c, c);
+ } else {
+ return Long.toString(millis);
+ }
+ }
+ /**
+ * Dump the current state.
+ *
+ * @param fd
+ * @param pw
+ * @param args
+ */
+ @Override
public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
- pw.println("DataConnection name=" + getName() + ":");
+ pw.print("DataConnection ");
+ super.dump(fd, pw, args);
pw.println(" mApnList=" + mApnList);
+ pw.flush();
pw.println(" mDataConnectionTracker=" + mDataConnectionTracker);
pw.println(" mApn=" + mApn);
pw.println(" mTag=" + mTag);
+ pw.flush();
pw.println(" phone=" + phone);
pw.println(" mRilVersion=" + mRilVersion);
pw.println(" cid=" + cid);
+ pw.flush();
pw.println(" mLinkProperties=" + mLinkProperties);
+ pw.flush();
pw.println(" mCapabilities=" + mCapabilities);
- pw.println(" createTime=" + createTime);
- pw.println(" lastFailTime=" + lastFailTime);
+ pw.println(" createTime=" + timeMillisToTimeOfDay(createTime));
+ pw.println(" lastFailTime=" + timeMillisToTimeOfDay(lastFailTime));
pw.println(" lastFailCause=" + lastFailCause);
+ pw.flush();
pw.println(" mRetryOverride=" + mRetryOverride);
pw.println(" mRefCount=" + mRefCount);
pw.println(" userData=" + userData);
- pw.println(" total messages=" + getProcessedMessagesCount());
- for (int i=0; i < getProcessedMessagesSize(); i++) {
- pw.printf(" msg[%d]=%s\n", i, getProcessedMessageInfo(i));
- }
+ pw.flush();
}
}
diff --git a/telephony/java/com/android/internal/telephony/DataConnectionAc.java b/telephony/java/com/android/internal/telephony/DataConnectionAc.java
index a9f2cd1..4744ff0 100644
--- a/telephony/java/com/android/internal/telephony/DataConnectionAc.java
+++ b/telephony/java/com/android/internal/telephony/DataConnectionAc.java
@@ -82,6 +82,51 @@
public static final int REQ_GET_RECONNECT_INTENT = BASE + 26;
public static final int RSP_GET_RECONNECT_INTENT = BASE + 27;
+ private static final int CMD_TO_STRING_COUNT = RSP_GET_RECONNECT_INTENT + 1;
+ private static String[] sCmdToString = new String[CMD_TO_STRING_COUNT];
+ static {
+ sCmdToString[REQ_IS_INACTIVE - BASE] = "REQ_IS_INACTIVE";
+ sCmdToString[RSP_IS_INACTIVE - BASE] = "RSP_IS_INACTIVE";
+ sCmdToString[REQ_GET_CID - BASE] = "REQ_GET_CID";
+ sCmdToString[RSP_GET_CID - BASE] = "RSP_GET_CID";
+ sCmdToString[REQ_GET_APNSETTING - BASE] = "REQ_GET_APNSETTING";
+ sCmdToString[RSP_GET_APNSETTING - BASE] = "RSP_GET_APNSETTING";
+ sCmdToString[REQ_GET_LINK_PROPERTIES - BASE] = "REQ_GET_LINK_PROPERTIES";
+ sCmdToString[RSP_GET_LINK_PROPERTIES - BASE] = "RSP_GET_LINK_PROPERTIES";
+ sCmdToString[REQ_SET_LINK_PROPERTIES_HTTP_PROXY - BASE] =
+ "REQ_SET_LINK_PROPERTIES_HTTP_PROXY";
+ sCmdToString[RSP_SET_LINK_PROPERTIES_HTTP_PROXY - BASE] =
+ "RSP_SET_LINK_PROPERTIES_HTTP_PROXY";
+ sCmdToString[REQ_GET_LINK_CAPABILITIES - BASE] = "REQ_GET_LINK_CAPABILITIES";
+ sCmdToString[RSP_GET_LINK_CAPABILITIES - BASE] = "RSP_GET_LINK_CAPABILITIES";
+ sCmdToString[REQ_UPDATE_LINK_PROPERTIES_DATA_CALL_STATE - BASE] =
+ "REQ_UPDATE_LINK_PROPERTIES_DATA_CALL_STATE";
+ sCmdToString[RSP_UPDATE_LINK_PROPERTIES_DATA_CALL_STATE - BASE] =
+ "RSP_UPDATE_LINK_PROPERTIES_DATA_CALL_STATE";
+ sCmdToString[REQ_RESET - BASE] = "REQ_RESET";
+ sCmdToString[RSP_RESET - BASE] = "RSP_RESET";
+ sCmdToString[REQ_GET_REFCOUNT - BASE] = "REQ_GET_REFCOUNT";
+ sCmdToString[RSP_GET_REFCOUNT - BASE] = "RSP_GET_REFCOUNT";
+ sCmdToString[REQ_ADD_APNCONTEXT - BASE] = "REQ_ADD_APNCONTEXT";
+ sCmdToString[RSP_ADD_APNCONTEXT - BASE] = "RSP_ADD_APNCONTEXT";
+ sCmdToString[REQ_REMOVE_APNCONTEXT - BASE] = "REQ_REMOVE_APNCONTEXT";
+ sCmdToString[RSP_REMOVE_APNCONTEXT - BASE] = "RSP_REMOVE_APNCONTEXT";
+ sCmdToString[REQ_GET_APNCONTEXT_LIST - BASE] = "REQ_GET_APNCONTEXT_LIST";
+ sCmdToString[RSP_GET_APNCONTEXT_LIST - BASE] = "RSP_GET_APNCONTEXT_LIST";
+ sCmdToString[REQ_SET_RECONNECT_INTENT - BASE] = "REQ_SET_RECONNECT_INTENT";
+ sCmdToString[RSP_SET_RECONNECT_INTENT - BASE] = "RSP_SET_RECONNECT_INTENT";
+ sCmdToString[REQ_GET_RECONNECT_INTENT - BASE] = "REQ_GET_RECONNECT_INTENT";
+ sCmdToString[RSP_GET_RECONNECT_INTENT - BASE] = "RSP_GET_RECONNECT_INTENT";
+ }
+ protected static String cmdToString(int cmd) {
+ cmd -= BASE;
+ if ((cmd >= 0) && (cmd < sCmdToString.length)) {
+ return sCmdToString[cmd];
+ } else {
+ return AsyncChannel.cmdToString(cmd + BASE);
+ }
+ }
+
/**
* enum used to notify action taken or necessary to be
* taken after the link property is changed.