hal: improve logging.

-log to print open/close/standby of out/in streams
-log to print the the device switches

Change-Id: I1b3bf3d6ba19faa4df804f781fc15c0f96a5b80f
diff --git a/hal/audio_hw.c b/hal/audio_hw.c
index 97fb87a..6b056ce 100644
--- a/hal/audio_hw.c
+++ b/hal/audio_hw.c
@@ -741,6 +741,8 @@
                                                                out_snd_device,
                                                                in_snd_device);
 
+    ALOGD("%s: done",__func__);
+
     return status;
 }
 
@@ -785,7 +787,8 @@
     struct audio_device *adev = in->dev;
 
     in->usecase = platform_update_usecase_from_source(in->source,in->usecase);
-    ALOGV("%s: enter: usecase(%d)", __func__, in->usecase);
+    ALOGD("%s: enter: stream(%p)usecase(%d: %s)",
+          __func__, &in->stream, in->usecase, use_case_table[in->usecase]);
 
     /* Check if source matches incall recording usecase criteria */
     ret = voice_check_and_set_incall_rec_usecase(adev, in);
@@ -1161,8 +1164,9 @@
     struct audio_usecase *uc_info;
     struct audio_device *adev = out->dev;
 
-    ALOGD("%s: enter: usecase(%d: %s) devices(%#x)",
-          __func__, out->usecase, use_case_table[out->usecase], out->devices);
+    ALOGD("%s: enter: stream(%p)usecase(%d: %s) devices(%#x)",
+          __func__, &out->stream, out->usecase, use_case_table[out->usecase],
+          out->devices);
     out->pcm_device_id = platform_get_pcm_device_id(out->usecase, PCM_PLAYBACK);
     if (out->pcm_device_id < 0) {
         ALOGE("%s: Invalid PCM device id(%d) for the usecase(%d)",
@@ -1343,13 +1347,13 @@
     struct stream_out *out = (struct stream_out *)stream;
     struct audio_device *adev = out->dev;
 
-    ALOGV("%s: enter: usecase(%d: %s)", __func__,
-          out->usecase, use_case_table[out->usecase]);
+    ALOGD("%s: enter: stream (%p) usecase(%d: %s)", __func__,
+          stream, out->usecase, use_case_table[out->usecase]);
     if (out->usecase == USECASE_COMPRESS_VOIP_CALL) {
         /* Ignore standby in case of voip call because the voip output
          * stream is closed in adev_close_output_stream()
          */
-        ALOGV("%s: Ignore Standby in VOIP call", __func__);
+        ALOGD("%s: Ignore Standby in VOIP call", __func__);
         return 0;
     }
 
@@ -1900,7 +1904,9 @@
     struct stream_in *in = (struct stream_in *)stream;
     struct audio_device *adev = in->dev;
     int status = 0;
-    ALOGV("%s: enter", __func__);
+    ALOGD("%s: enter: stream (%p) usecase(%d: %s)", __func__,
+          stream, in->usecase, use_case_table[in->usecase]);
+
 
     if (in->usecase == USECASE_COMPRESS_VOIP_CALL) {
         /* Ignore standby in case of voip call because the voip input
@@ -1940,7 +1946,7 @@
     char value[32];
     int ret = 0, val = 0, err;
 
-    ALOGV("%s: enter: kvpairs=%s", __func__, kvpairs);
+    ALOGD("%s: enter: kvpairs=%s", __func__, kvpairs);
     parms = str_parms_create_str(kvpairs);
 
     pthread_mutex_lock(&in->lock);
@@ -2123,11 +2129,14 @@
     struct stream_out *out;
     int i, ret = 0;
 
-    ALOGV("%s: enter: sample_rate(%d) channel_mask(%#x) devices(%#x) flags(%#x)",
-          __func__, config->sample_rate, config->channel_mask, devices, flags);
     *stream_out = NULL;
     out = (struct stream_out *)calloc(1, sizeof(struct stream_out));
 
+    ALOGD("%s: enter: sample_rate(%d) channel_mask(%#x) devices(%#x) flags(%#x)\
+        stream_handle(%p)",__func__, config->sample_rate, config->channel_mask,
+        devices, flags, &out->stream);
+
+
     if (!out) {
         return -ENOMEM;
     }
@@ -2184,9 +2193,6 @@
             goto error_open;
         }
     } else if (out->flags & AUDIO_OUTPUT_FLAG_COMPRESS_OFFLOAD) {
-        ALOGD("%s: copl(%x): sample_rate(%d) channel_mask(%#x) devices(%#x) flags(%#x)",
-              __func__, (unsigned int)out, config->sample_rate, config->channel_mask, devices, flags);
-
         if (config->offload_info.version != AUDIO_INFO_INITIALIZER.version ||
             config->offload_info.size != AUDIO_INFO_INITIALIZER.size) {
             ALOGE("%s: Unsupported Offload information", __func__);
@@ -2331,6 +2337,8 @@
     config->sample_rate = out->stream.common.get_sample_rate(&out->stream.common);
 
     *stream_out = &out->stream;
+    ALOGD("%s: Stream (%p) picks up usecase (%s)", __func__, &out->stream,
+        use_case_table[out->usecase]);
     ALOGV("%s: exit", __func__);
     return 0;
 
@@ -2348,7 +2356,8 @@
     struct audio_device *adev = out->dev;
     int ret = 0;
 
-    ALOGV("%s: enter", __func__);
+    ALOGD("%s: enter:stream_handle(%p)",__func__, out);
+
     if (out->usecase == USECASE_COMPRESS_VOIP_CALL) {
         ret = voice_extn_compress_voip_close_output_stream(&stream->common);
         if(ret != 0)
@@ -2560,12 +2569,15 @@
     int ret = 0, buffer_size, frame_size;
     int channel_count = popcount(config->channel_mask);
 
-    ALOGV("%s: enter", __func__);
+
     *stream_in = NULL;
     if (check_input_parameters(config->sample_rate, config->format, channel_count) != 0)
         return -EINVAL;
 
     in = (struct stream_in *)calloc(1, sizeof(struct stream_in));
+    ALOGD("%s: enter: sample_rate(%d) channel_mask(%#x) devices(%#x)\
+        stream_handle(%p)",__func__, config->sample_rate, config->channel_mask,
+        devices, &in->stream);
 
     pthread_mutex_init(&in->lock, (const pthread_mutexattr_t *) NULL);
 
@@ -2636,7 +2648,7 @@
 {
     int ret;
     struct stream_in *in = (struct stream_in *)stream;
-    ALOGV("%s", __func__);
+    ALOGD("%s: enter:stream_handle(%p)",__func__, in);
 
     if (in->usecase == USECASE_COMPRESS_VOIP_CALL) {
         ret = voice_extn_compress_voip_close_input_stream(&stream->common);