Created a media_plugin_gstreamer010.log file in the cwd for the GStreamer plugin

1 files changed, 96 insertions, 68 deletions

diff --git a/linden/indra/media_plugins/gstreamer010/media_plugin_gstreamer010.cpp b/linden/indra/media_plugins/gstreamer010/media_plugin_gstreamer010.cpp
index ed6d920..fbe3e49 100755
--- a/linden/indra/media_plugins/gstreamer010/media_plugin_gstreamer010.cpp
+++ b/linden/indra/media_plugins/gstreamer010/media_plugin_gstreamer010.cpp
@@ -83,6 +83,9 @@ public:
         gboolean processGSTEvents(GstBus     *bus,
                                   GstMessage *message);
 
+        // basic log file writing
+        static bool writeToLog(char* str, ...);
+
 private:
         std::string getVersion();
         bool navigateTo( const std::string urlIn );
@@ -178,8 +181,7 @@ MediaPluginGStreamer010::MediaPluginGStreamer010(
         mVideoSink ( NULL ),
         mCommand ( COMMAND_NONE )
 {
-        std::ostringstream str;
-        INFOMSG("MediaPluginGStreamer010 constructor - my PID=%u", U32(LL_GETPID()));
+        writeToLog("MediaPluginGStreamer010 PID=%u", U32(LL_GETPID()));
 }
 
 ///////////////////////////////////////////////////////////////////////////////
@@ -199,6 +201,29 @@ static char* get_gst_state_name(GstState state)
 }
 #endif // LL_GST_REPORT_STATE_CHANGES
 
+// static
+bool MediaPluginGStreamer010::writeToLog(char* str, ...)
+{
+        LLFILE* fp = LLFile::fopen("media_plugin_gstreamer010.log", "a");
+
+    if (!fp)
+        {
+          return false;
+        }
+
+        time_t timeptr = time(NULL);
+        struct tm* ltime = localtime(&timeptr);
+        fprintf(fp, "[%d:%d:%d] ", ltime->tm_hour, ltime->tm_min, ltime->tm_sec);
+    va_list arglist;
+    va_start(arglist, str);
+    vfprintf(fp, str, arglist);
+    va_end(arglist);
+    fprintf(fp, " \n");
+        fclose(fp);
+
+    return true;
+}
+
 gboolean
 MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                                           GstMessage *message)
@@ -206,17 +231,11 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
         if (!message) 
                 return TRUE; // shield against GStreamer bug
 
+        // TODO: grok 'duration' message type
         if (GST_MESSAGE_TYPE(message) != GST_MESSAGE_STATE_CHANGED &&
-            GST_MESSAGE_TYPE(message) != GST_MESSAGE_BUFFERING)
+            GST_MESSAGE_TYPE(message) != GST_MESSAGE_TAG)
         {
-                DEBUGMSG("Got GST message type: %s",
-                        GST_MESSAGE_TYPE_NAME (message));
-        }
-        else
-        {
-                // TODO: grok 'duration' message type
-                DEBUGMSG("Got GST message type: %s",
-                         GST_MESSAGE_TYPE_NAME (message));
+                writeToLog("Got GST message type: %s", GST_MESSAGE_TYPE_NAME (message));
         }
 
         switch (GST_MESSAGE_TYPE (message))
@@ -226,7 +245,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                         // NEEDS GST 0.10.11+ and America discovered by C.Columbus
                         gint percent = 0;
                         gst_message_parse_buffering(message, &percent);
-                        DEBUGMSG("GST buffering: %d%%", percent);
+                        writeToLog("GST buffering: %d%%", percent);
 
                         break;
                 }
@@ -240,7 +259,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                                                         &pending_state);
                         #ifdef LL_GST_REPORT_STATE_CHANGES
                         // not generally very useful, and rather spammy.
-                        DEBUGMSG("state change (old,<new>,pending): %s,<%s>,%s",
+                        writeToLog("state change (old,<new>,pending): %s,<%s>,%s",
                                 get_gst_state_name(old_state),
                                 get_gst_state_name(new_state),
                                 get_gst_state_name(pending_state));
@@ -270,7 +289,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                         gchar *debug = NULL;
         
                         gst_message_parse_error (message, &err, &debug);
-                        WARNMSG("GST error: %s", err?err->message:"(unknown)");
+                        writeToLog("GST error: %s", err?err->message:"(unknown)");
                         if (err)
                                 g_error_free (err);
                         g_free (debug);
@@ -287,7 +306,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                         gchar *debug = NULL;
                         
                         gst_message_parse_info (message, &err, &debug);
-                        INFOMSG("GST info: %s", err?err->message:"(unknown)");
+                        writeToLog("GST info: %s", err?err->message:"(unknown)");
                         if (err)
                                 g_error_free (err);
                         g_free (debug);
@@ -300,7 +319,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                         gchar *debug = NULL;
         
                         gst_message_parse_warning (message, &err, &debug);
-                        WARNMSG("GST warning: %s", err?err->message:"(unknown)");
+                        writeToLog("GST warning: %s", err?err->message:"(unknown)");
                         if (err)
                                 g_error_free (err);
                         g_free (debug);
@@ -317,7 +336,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
 
                         if ( gst_tag_list_get_string(new_tags, GST_TAG_TITLE, &title) )
                         {
-                                //WARMING("Title: %s", title);
+                                //writeToLog("Title: %s", title);
                                 std::string newtitle(title);
                                 gst_tag_list_free(new_tags);
 
@@ -336,10 +355,10 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                 case GST_MESSAGE_EOS:
                 {
                         /* end-of-stream */
-                        DEBUGMSG("GST end-of-stream.");
+                        writeToLog("GST end-of-stream.");
                         if (mIsLooping)
                         {
-                                DEBUGMSG("looping media...");
+                                //writeToLog("looping media...");
                                 double eos_pos_sec = 0.0F;
                                 bool got_eos_position = getTimePos(eos_pos_sec);
         
@@ -348,7 +367,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                                         // if we know that the movie is really short, don't
                                         // loop it else it can easily become a time-hog
                                         // because of GStreamer spin-up overhead
-                                        DEBUGMSG("really short movie (%0.3fsec) - not gonna loop this, pausing instead.", eos_pos_sec);
+                                        writeToLog("really short movie (%0.3fsec) - not gonna loop this, pausing instead.", eos_pos_sec);
                                         // inject a COMMAND_PAUSE
                                         mCommand = COMMAND_PAUSE;
                                 }
@@ -367,7 +386,7 @@ MediaPluginGStreamer010::processGSTEvents(GstBus     *bus,
                                         else
                                         #endif // LLGST_LOOP_BY_SEEKING
                                         {  // use clumsy stop-start to loop
-                                                DEBUGMSG("didn't loop by rewinding - stopping and starting instead...");
+                                                writeToLog("didn't loop by rewinding - stopping and starting instead...");
                                                 stop();
                                                 play(1.0);
                                         }
@@ -413,7 +432,7 @@ MediaPluginGStreamer010::navigateTo ( const std::string urlIn )
 
         setStatus(STATUS_LOADING);
 
-        DEBUGMSG("Setting media URI: %s", urlIn.c_str());
+        writeToLog("Setting media URI: %s", urlIn.c_str());
 
         mSeekWanted = false;
 
@@ -441,13 +460,13 @@ MediaPluginGStreamer010::update(int milliseconds)
         if (!mDoneInit)
                 return false; // error
 
-        DEBUGMSG("updating media...");
+        //writeToLog("updating media...");
         
         // sanity check
         if (NULL == mPump ||
             NULL == mPlaybin)
         {
-                DEBUGMSG("dead media...");
+                writeToLog("dead media...");
                 return false;
         }
 
@@ -477,7 +496,7 @@ MediaPluginGStreamer010::update(int milliseconds)
                 GST_OBJECT_LOCK(mVideoSink);
                 if (mVideoSink->retained_frame_ready)
                 {
-                        DEBUGMSG("NEW FRAME READY");
+                        writeToLog("NEW FRAME READY");
 
                         if (mVideoSink->retained_frame_width != mCurrentWidth ||
                             mVideoSink->retained_frame_height != mCurrentHeight)
@@ -508,7 +527,7 @@ MediaPluginGStreamer010::update(int milliseconds)
                                 GST_OBJECT_UNLOCK(mVideoSink);
 
                                 mCurrentRowbytes = neww * newd;
-                                DEBUGMSG("video container resized to %dx%d",
+                                writeToLog("video container resized to %dx%d",
                                          neww, newh);
 
                                 mDepth = newd;
@@ -536,7 +555,7 @@ MediaPluginGStreamer010::update(int milliseconds)
                                 }
 
                                 GST_OBJECT_UNLOCK(mVideoSink);
-                                DEBUGMSG("NEW FRAME REALLY TRULY CONSUMED, TELLING HOST");
+                                writeToLog("NEW FRAME REALLY TRULY CONSUMED, TELLING HOST");
 
                                 setDirty(0,0,mCurrentWidth,mCurrentHeight);
                         }
@@ -547,7 +566,7 @@ MediaPluginGStreamer010::update(int milliseconds)
 
                                 GST_OBJECT_UNLOCK(mVideoSink);
 
-                                DEBUGMSG("NEW FRAME not consumed, still waiting for a shm segment and/or shm resize");
+                                writeToLog("NEW FRAME not consumed, still waiting for a shm segment and/or shm resize");
                         }
 
                         return true;
@@ -586,7 +605,7 @@ MediaPluginGStreamer010::mouseMove( int x, int y )
 bool
 MediaPluginGStreamer010::pause()
 {
-        DEBUGMSG("pausing media...");
+        writeToLog("pausing media...");
         // todo: error-check this?
         gst_element_set_state(mPlaybin, GST_STATE_PAUSED);
         return true;
@@ -595,7 +614,7 @@ MediaPluginGStreamer010::pause()
 bool
 MediaPluginGStreamer010::stop()
 {
-        DEBUGMSG("stopping media...");
+        writeToLog("stopping media...");
         // todo: error-check this?
         gst_element_set_state(mPlaybin, GST_STATE_READY);
         return true;
@@ -605,8 +624,7 @@ bool
 MediaPluginGStreamer010::play(double rate)
 {
         // NOTE: we don't actually support non-natural rate.
-
-        DEBUGMSG("playing media... rate=%f", rate);
+        writeToLog("playing media... rate=%f", rate);
         // todo: error-check this?
         gst_element_set_state(mPlaybin, GST_STATE_PLAYING);
         return true;
@@ -643,7 +661,7 @@ MediaPluginGStreamer010::seek(double time_sec)
                                 GST_SEEK_TYPE_SET, gint64(time_sec*GST_SECOND),
                                 GST_SEEK_TYPE_NONE, GST_CLOCK_TIME_NONE);
         }
-        DEBUGMSG("MEDIA SEEK REQUEST to %fsec result was %d",
+        writeToLog("MEDIA SEEK REQUEST to %f sec result was %d",
                  float(time_sec), int(success));
         return success;
 }
@@ -697,7 +715,7 @@ MediaPluginGStreamer010::load()
 
         setStatus(STATUS_LOADING);
 
-        DEBUGMSG("setting up media...");
+        writeToLog("setting up media...");
 
         mIsLooping = false;
         mVolume = (float) 0.1234567; // minor hack to force an initial volume update
@@ -736,7 +754,7 @@ MediaPluginGStreamer010::load()
                         GST_SLVIDEO(gst_element_factory_make ("private-slvideo", "slvideo"));
                 if (!mVideoSink)
                 {
-                        WARNMSG("Could not instantiate private-slvideo element.");
+                        writeToLog("Could not instantiate private-slvideo element.");
                         // todo: cleanup.
                         setStatus(STATUS_ERROR);
                         return false; // error
@@ -755,7 +773,7 @@ MediaPluginGStreamer010::unload ()
         if (!mDoneInit)
                 return false; // error
 
-        DEBUGMSG("unloading media...");
+        writeToLog("unloading media...");
         
         // stop getting callbacks for this bus
         g_source_remove(mBusWatchID);
@@ -813,7 +831,7 @@ MediaPluginGStreamer010::startup()
                                     "libgstvideo-0.10.so.0") )
 #endif
                 {
-                        WARNMSG("Couldn't find suitable GStreamer 0.10 support on this system - video playback disabled.");
+                        writeToLog("Couldn't find suitable GStreamer 0.10 support on this system - video playback disabled.");
                         return false;
                 }
 */
@@ -823,7 +841,7 @@ MediaPluginGStreamer010::startup()
 //              }
 //              else
 //              {
-//                      WARNMSG("gst_segtrap_set_enabled() is not available; plugin crashes won't be caught.");
+//                      writeToLog("gst_segtrap_set_enabled() is not available; plugin crashes won't be caught.");
 //              }
 /*
 #if LL_LINUX
@@ -866,12 +884,12 @@ MediaPluginGStreamer010::startup()
                 {
                         if (err)
                         {
-                                WARNMSG("GST init failed: %s", err->message);
+                                writeToLog("GST init failed: %s", err->message);
                                 g_error_free(err);
                         }
                         else
                         {
-                                WARNMSG("GST init failed for unspecified reason.");
+                                writeToLog("GST init failed for unspecified reason.");
                         }
                         return false;
                 }
@@ -882,22 +900,22 @@ MediaPluginGStreamer010::startup()
 
                 // Init our custom plugins - only really need do this once.
                 gst_slvideo_init_class();
-/*
+
                 // List the plugins GStreamer can find
-                LL_DEBUGS("MediaImpl") << "Found GStreamer plugins:" << LL_ENDL;
+                writeToLog("Found GStreamer plugins:");
                 GList *list;
                 GstRegistry *registry = gst_registry_get_default();
-                std::string loaded = "";
+                std::string loaded = "No";
                 for (list = gst_registry_get_plugin_list(registry);
                      list != NULL;
                      list = g_list_next(list))
                 {        
                         GstPlugin *list_plugin = (GstPlugin *)list->data;
-                        (bool)gst_plugin_is_loaded(list_plugin) ? loaded = "Yes" : loaded = "No";
-                        LL_DEBUGS("MediaImpl") << gst_plugin_get_name(list_plugin) << ", loaded? " << loaded << LL_ENDL;
+                        if (gst_plugin_is_loaded(list_plugin)) loaded = "Yes";
+                        writeToLog("%s, loaded? %s", gst_plugin_get_name(list_plugin), loaded.c_str());
                 }
                 gst_plugin_list_free(list);
-*/
+
                 mDoneInit = true;
         }
 
@@ -941,11 +959,11 @@ void MediaPluginGStreamer010::set_gst_plugin_path()
 
         if( imp_dir == "" )
         {
-                WARNMSG("Could not get application directory, not setting GST_PLUGIN_PATH.");
+                writeToLog("Could not get application directory, not setting GST_PLUGIN_PATH.");
                 return;
         }
 
-        DEBUGMSG("Imprudence is installed at %s", imp_dir);
+        writeToLog("Imprudence is installed at %s", imp_dir.c_str());
 
         // ":" on Mac and 'Nix, ";" on Windows
         std::string separator = G_SEARCHPATH_SEPARATOR_S;
@@ -955,7 +973,7 @@ void MediaPluginGStreamer010::set_gst_plugin_path()
         char *old_path = getenv("GST_PLUGIN_PATH");
         if(old_path == NULL)
         {
-                DEBUGMSG("Did not find user-set GST_PLUGIN_PATH.");
+                writeToLog("Did not find user-set GST_PLUGIN_PATH.");
         }
         else
         {
@@ -986,11 +1004,11 @@ void MediaPluginGStreamer010::set_gst_plugin_path()
 
         if( put_result == -1 )
         {
-                WARNMSG("Setting GST_PLUGIN_PATH failed!");
+                writeToLog("Setting GST_PLUGIN_PATH failed!");
         }
         else
         {
-                DEBUGMSG("GST_PLUGIN_PATH set to %s", getenv("GST_PLUGIN_PATH"));
+                writeToLog("GST_PLUGIN_PATH set to %s", getenv("GST_PLUGIN_PATH"));
         }
                 
         // Don't load system plugins. We only want to use ours, to avoid conflicts.
@@ -1002,7 +1020,7 @@ void MediaPluginGStreamer010::set_gst_plugin_path()
 
         if( put_result == -1 )
         {
-                WARNMSG("Setting GST_PLUGIN_SYSTEM_PATH=\"\" failed!");
+                writeToLog("Setting GST_PLUGIN_SYSTEM_PATH=\"\" failed!");
         }
                 
 #endif // LL_WINDOWS || LL_DARWIN
@@ -1020,7 +1038,7 @@ MediaPluginGStreamer010::sizeChanged()
         {
                 mNaturalWidth = mCurrentWidth;
                 mNaturalHeight = mCurrentHeight;
-                DEBUGMSG("Media NATURAL size better detected as %dx%d",
+                writeToLog("Media NATURAL size better detected as %dx%d",
                          mNaturalWidth, mNaturalHeight);
         }
 
@@ -1035,7 +1053,7 @@ MediaPluginGStreamer010::sizeChanged()
                 message.setValue("name", mTextureSegmentName);
                 message.setValueS32("width", mNaturalWidth);
                 message.setValueS32("height", mNaturalHeight);
-                DEBUGMSG("<--- Sending size change request to application with name: '%s' - natural size is %d x %d", mTextureSegmentName.c_str(), mNaturalWidth, mNaturalHeight);
+                writeToLog("<--- Sending size change request to application with name: '%s' - natural size is %d x %d", mTextureSegmentName.c_str(), mNaturalWidth, mNaturalHeight);
                 sendMessage(message);
         }
 }
@@ -1058,11 +1076,11 @@ MediaPluginGStreamer010::closedown()
 
 MediaPluginGStreamer010::~MediaPluginGStreamer010()
 {
-        DEBUGMSG("MediaPluginGStreamer010 destructor");
+        //writeToLog("MediaPluginGStreamer010 destructor");
 
         closedown();
 
-        DEBUGMSG("GStreamer010 closing down");
+        writeToLog("GStreamer010 closing down");
 }
 
 
@@ -1085,7 +1103,7 @@ MediaPluginGStreamer010::getVersion()
 
 void MediaPluginGStreamer010::receiveMessage(const char *message_string)
 {
-        //std::cerr << "MediaPluginGStreamer010::receiveMessage: received message: \"" << message_string << "\"" << std::endl;
+        //std::cerr << "MediaPluginGStreamer010::receiveMessage: received message: \"" << message_string << "\"";
 
         LLPluginMessage message_in;
 
@@ -1106,11 +1124,11 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
 
                                 if ( load() )
                                 {
-                                        DEBUGMSG("GStreamer010 media instance set up");
+                                        writeToLog("GStreamer010 media instance set up");
                                 }
                                 else
                                 {
-                                        WARNMSG("GStreamer010 media instance failed to set up");
+                                        writeToLog("GStreamer010 media instance failed to set up");
                                 }
 
                                 message.setValue("plugin_version", getVersion());
@@ -1137,7 +1155,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                                 std::string name = message_in.getValue("name");
 
                                 std::ostringstream str;
-                                INFOMSG("MediaPluginGStreamer010::receiveMessage: shared memory added, name: %s, size: %d, address: %p", name.c_str(), int(info.mSize), info.mAddress);
+                                writeToLog("MediaPluginGStreamer010::receiveMessage: shared memory added, name: %s, size: %d, address: %p", name.c_str(), int(info.mSize), info.mAddress);
 
                                 mSharedSegments.insert(SharedSegmentMap::value_type(name, info));
                         }
@@ -1145,7 +1163,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                         {
                                 std::string name = message_in.getValue("name");
 
-                                DEBUGMSG("MediaPluginGStreamer010::receiveMessage: shared memory remove, name = %s", name.c_str());
+                                writeToLog("MediaPluginGStreamer010::receiveMessage: shared memory remove, name = %s", name.c_str());
                                 
                                 SharedSegmentMap::iterator iter = mSharedSegments.find(name);
                                 if(iter != mSharedSegments.end())
@@ -1163,7 +1181,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                                 }
                                 else
                                 {
-                                        WARNMSG("MediaPluginGStreamer010::receiveMessage: unknown shared memory region!");
+                                        writeToLog("MediaPluginGStreamer010::receiveMessage: unknown shared memory region!");
                                 }
 
                                 // Send the response so it can be cleaned up.
@@ -1174,7 +1192,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                         else
                         {
                                 std::ostringstream str;
-                                INFOMSG("MediaPluginGStreamer010::receiveMessage: unknown base message: %s", message_name.c_str());
+                                writeToLog("MediaPluginGStreamer010::receiveMessage: unknown base message: %s", message_name.c_str());
                         }
                 }
                 else if(message_class == LLPLUGIN_MESSAGE_CLASS_MEDIA)
@@ -1217,7 +1235,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                                 S32 texture_height = message_in.getValueS32("texture_height");
 
                                 std::ostringstream str;
-                                INFOMSG("---->Got size change instruction from application with shm name: %s - size is %d x %d", name.c_str(), width, height);
+                                writeToLog("---->Got size change instruction from application with shm name: %s - size is %d x %d", name.c_str(), width, height);
 
                                 LLPluginMessage message(LLPLUGIN_MESSAGE_CLASS_MEDIA, "size_change_response");
                                 message.setValue("name", name);
@@ -1233,8 +1251,8 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                                         SharedSegmentMap::iterator iter = mSharedSegments.find(name);
                                         if(iter != mSharedSegments.end())
                                         {
-                                                INFOMSG("*** Got size change with matching shm, new size is %d x %d", width, height);
-                                                INFOMSG("*** Got size change with matching shm, texture size size is %d x %d", texture_width, texture_height);
+                                                writeToLog("*** Got size change with matching shm, new size is %d x %d", width, height);
+                                                writeToLog("*** Got size change with matching shm, texture size size is %d x %d", texture_width, texture_height);
 
                                                 mPixels = (unsigned char*)iter->second.mAddress;
                                                 mTextureSegmentName = name;
@@ -1244,7 +1262,7 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                                                 if (texture_width > 1 ||
                                                     texture_height > 1) // not a dummy size from the app, a real explicit forced size
                                                 {
-                                                        INFOMSG("**** = REAL RESIZE REQUEST FROM APP");
+                                                        writeToLog("**** = REAL RESIZE REQUEST FROM APP");
                                                         
                                                         GST_OBJECT_LOCK(mVideoSink);
                                                         mVideoSink->resize_forced_always = true;
@@ -1326,13 +1344,23 @@ void MediaPluginGStreamer010::receiveMessage(const char *message_string)
                 }
                 else
                 {
-                        INFOMSG("MediaPluginGStreamer010::receiveMessage: unknown message class: %s", message_class.c_str());
+                        writeToLog("MediaPluginGStreamer010::receiveMessage: unknown message class: %s", message_class.c_str());
                 }
         }
 }
 
 int init_media_plugin(LLPluginInstance::sendMessageFunction host_send_func, void *host_user_data, LLPluginInstance::sendMessageFunction *plugin_send_func, void **plugin_user_data)
 {
+        // init log file
+        LLFILE* fp = LLFile::fopen("media_plugin_gstreamer010.log", "w");
+        if (fp)
+        {
+                time_t timeptr = time(NULL);
+                fprintf(fp, "%s", asctime(localtime(&timeptr)));
+                fprintf(fp, "<--- Begin media_plugin_gstreamer010 initialization --->\n");
+                fclose(fp);
+        }
+
         if (MediaPluginGStreamer010::startup())
         {
                 MediaPluginGStreamer010 *self = new MediaPluginGStreamer010(host_send_func, host_user_data);