Subject: PATCH: To fix the issue where message panel was showing incomplete info (pgAdmin4)

From: Murtuza Zabuawala <[email-masked]>
Date: Tue, 9 Aug 2016 12:37:54 +0530

Hi,

PFA patch to fix the issue where message panel was showing incomplete info.
We may still miss some messages from Psycopg2 driver due to limited size of
notices queue.
(RM#1523)

Regards,
Murtuza
diff --git a/web/pgadmin/tools/sqleditor/__init__.py b/web/pgadmin/tools/sqleditor/__init__.py
index bb5c26b..2389217 100644
--- a/web/pgadmin/tools/sqleditor/__init__.py
+++ b/web/pgadmin/tools/sqleditor/__init__.py
@@ -406,8 +406,10 @@ def poll(trans_id):
         trans_id: unique transaction id
     """
     col_info = None
+    result = None
     primary_keys = None
     rows_affected = 0
+    additional_result = []
 
     # Check the transaction and connection status
     status, error_msg, conn, trans_obj, session_obj = check_transaction_status(trans_id)
@@ -450,20 +452,25 @@ def poll(trans_id):
         # restore it and update the session variable.
         session_obj['columns_info'] = columns
         update_session_grid_transaction(trans_id, session_obj)
-    else:
-        if result is None:
-            result = conn.status_message()
-            additional_result = conn.messages()
-            """
-            Procedure/Function output may comes in the form of Notices from the
-            database server, so we need to append those outputs with the
-            original result.
-            """
-            if isinstance(additional_result, list) \
-                    and len(additional_result) > 0:
-                result = "{0} {1}".format(additional_result[-1], result)
-
-            rows_affected = conn.rows_affected()
+
+    """
+        Procedure/Function output may comes in the form of Notices from the
+        database server, so we need to append those outputs with the
+        original result.
+    """
+    if status == 'Success' and result is None:
+        result = conn.status_message()
+        messages = conn.messages()
+        if messages:
+            additional_result = ''.join(messages)
+        else:
+            additional_result = ''
+        if result != 'SELECT 1' and result is not None:
+            result = additional_result + result
+        else:
+            result = additional_result
+
+        rows_affected = conn.rows_affected()
 
     return make_json_response(
         data={
diff --git a/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js b/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
index 2be2b49..ce421e5 100644
--- a/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
+++ b/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
@@ -1282,7 +1282,9 @@ define(
                     else {
                       // Show message in message and history tab in case of query tool
                       self.total_time = self.get_query_run_time(self.query_start_time, self.query_end_time);
-                      self.update_msg_history(true, res.data.result);
+                      self.update_msg_history(true, res.data.result, false);
+                      var msg = S('{{ _('Total query runtime: %s.') }}').sprintf(self.total_time).value();
+                      alertify.success(msg, self.info_notifier_timeout);
                     }
 
                     // Enable/Disable query tool button only if is_query_tool is true.
@@ -1292,6 +1294,9 @@ define(
                     }
                   }
                   else if (res.data.status === 'Busy') {
+                    if (res.data.result) {
+                      self.update_msg_history(true, res.data.result, false);
+                    }
                     // If status is Busy then poll the result by recursive call to the poll function
                     self._poll();
                   }
@@ -1302,10 +1307,10 @@ define(
                       self.disable_tool_buttons(false);
                       $("#btn-cancel-query").prop('disabled', true);
                     }
-                    self.update_msg_history(false, res.data.result);
+                    self.update_msg_history(false, res.data.result, true);
                   }
                   else if (res.data.status === 'Cancel') {
-                    self.update_msg_history(false, "Execution Cancelled!")
+                    self.update_msg_history(false, "Execution Cancelled!", true)
                   }
                 },
                 error: function(e) {
@@ -1681,29 +1686,33 @@ define(
             clear_grid = true;
 
           self.trigger('pgadmin-sqleditor:loading-icon:hide');
-          $("#btn-flash").prop('disabled', false);
 
-          $('.sql-editor-message').text(msg);
+          $("#btn-flash").prop('disabled', false);
           self.gridView.messages_panel.focus();
 
-          if (self.is_query_tool && clear_grid) {
-            // Delete grid and paginator
-            if (self.gridView.grid) {
-              self.gridView.grid.remove();
+          if (self.is_query_tool) {
+            if (clear_grid) {
+              // Delete grid and paginator
+              if (self.gridView.grid) {
+                self.gridView.grid.remove();
+              }
+              // Misc cleaning
               self.columns = undefined;
               self.collection = undefined;
-            }
 
-            if (self.gridView.paginator)
-             self.gridView.paginator.remove();
+              if (self.gridView.paginator)
+                self.gridView.paginator.remove();
+              $('.sql-editor-message').text(msg);
+            } else {
+              $('.sql-editor-message').append(msg);
+            }
           }
 
-          self.gridView.history_collection.add(
-            {'status' : status, 'start_time': self.query_start_time.toString(),
-             'query': self.query, 'row_affected': self.rows_affected,
-             'total_time': self.total_time, 'message':msg
+          self.gridView.history_collection.add({
+            'status' : status, 'start_time': self.query_start_time.toString(),
+            'query': self.query, 'row_affected': self.rows_affected,
+            'total_time': self.total_time, 'message':msg
           });
-
           self.gridView.history_collection.sort();
         },
 
@@ -2129,10 +2138,12 @@ define(
           var self = this;
 
           // Start execution of the query.
-          if (self.is_query_tool)
+          if (self.is_query_tool) {
+            $('.sql-editor-message').html('');
             self._execute();
-          else
+          } else {
             self._execute_data_query();
+          }
         },
 
         // This function will show the filter in the text area.
diff --git a/web/pgadmin/utils/driver/psycopg2/__init__.py b/web/pgadmin/utils/driver/psycopg2/__init__.py
index fbde603..bded931 100644
--- a/web/pgadmin/utils/driver/psycopg2/__init__.py
+++ b/web/pgadmin/utils/driver/psycopg2/__init__.py
@@ -178,6 +178,7 @@ class Connection(BaseConnection):
         self.__backend_pid = None
         self.execution_aborted = False
         self.row_count = 0
+        self.__notices = None
 
         super(Connection, self).__init__()
 
@@ -639,6 +640,7 @@ Attempt to reconnect it failed with the error:
         )
 
         try:
+            self.__notices = []
             self.execution_aborted = False
             cur.execute(query, params)
             res = self._wait_timeout(cur.connection, ASYNC_WAIT_TIMEOUT)
@@ -904,31 +906,9 @@ Failed to reset the connection to the server due to following error:
         if state == psycopg2.extensions.POLL_OK:
             return self.ASYNC_OK
         elif state == psycopg2.extensions.POLL_WRITE:
-            # Wait for the given time and then check the return status
-            # If three empty lists are returned then the time-out is reached.
-            timeout_status = select.select([], [conn.fileno()], [], time)
-            if timeout_status == ([], [], []):
-                return self.ASYNC_WRITE_TIMEOUT
-
-            # poll again to check the state if it is still POLL_WRITE
-            # then return ASYNC_WRITE_TIMEOUT else return ASYNC_OK.
-            state = conn.poll()
-            if state == psycopg2.extensions.POLL_WRITE:
-                return self.ASYNC_WRITE_TIMEOUT
-            return self.ASYNC_OK
+            return self.ASYNC_WRITE_TIMEOUT
         elif state == psycopg2.extensions.POLL_READ:
-            # Wait for the given time and then check the return status
-            # If three empty lists are returned then the time-out is reached.
-            timeout_status = select.select([conn.fileno()], [], [], time)
-            if timeout_status == ([], [], []):
-                return self.ASYNC_READ_TIMEOUT
-
-            # poll again to check the state if it is still POLL_READ
-            # then return ASYNC_READ_TIMEOUT else return ASYNC_OK.
-            state = conn.poll()
-            if state == psycopg2.extensions.POLL_READ:
-                return self.ASYNC_READ_TIMEOUT
-            return self.ASYNC_OK
+            return self.ASYNC_READ_TIMEOUT
         else:
             raise psycopg2.OperationalError(
                 "poll() returned %s from _wait_timeout function" % state
@@ -965,6 +945,10 @@ Failed to reset the connection to the server due to following error:
             errmsg = self._formatted_exception_msg(pe, formatted_exception_msg)
             return False, errmsg, None
 
+        if self.conn.notices and self.__notices is not None:
+            while self.conn.notices:
+                self.__notices.append(self.conn.notices.pop(0)[:])
+
         colinfo = None
         result = None
         self.row_count = 0
@@ -996,7 +980,6 @@ Failed to reset the connection to the server due to following error:
                         result.append(dict(row))
                 except psycopg2.ProgrammingError:
                     result = None
-
         return status, result, colinfo
 
     def status_message(self):
@@ -1094,7 +1077,7 @@ Failed to reset the connection to the server due to following error:
         """
         Returns the list of the messages/notices send from the database server.
         """
-        return self.conn.notices if self.conn else []
+        return self.__notices
 
     def _formatted_exception_msg(self, exception_obj, formatted_msg):
         """

-- 
Sent via pgadmin-hackers mailing list ([email-masked])
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgadmin-hackers

---

From: Dave Page <[email-masked]>
Date: Tue, 9 Aug 2016 13:58:18 +0100

Hi

> We may still miss some messages from Psycopg2 driver due to limited size of

A few thoughts on this (mostly based on my discussions with Ashesh):

1) You seem to have removed the poll delay. I assume that is to try to
avoid missing messages? Can we re-introduce the delay (to avoid
excessive network requests), but collect messages while we're waiting?

2) If I run VACUUM, whilst I see messages as I should now, there is no
query time summary as there is for a query that returns data.

3) Can we incrementally display messages? e.g. each time we poll, we
add the new messages to the messages div, and scroll to the end
automatically?

-- 
Dave Page
Blog: http://pgsnake.blogspot.com
Twitter: @pgsnake

EnterpriseDB UK: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

---

From: Ashesh Vashi <[email-masked]>
Date: Tue, 9 Aug 2016 18:31:41 +0530

> excessive network requests), but collect messages while we're waiting?
Using thread?
Start a thread during the timeout?

> add the new messages to the messages div, and scroll to the end

Yeah - that's a good idea.

--

Thanks & Regards,

Ashesh Vashi
EnterpriseDB INDIA: Enterprise PostgreSQL Company
<http://www.enterprisedb.com/>

*http://www.linkedin.com/in/asheshvashi*
<http://www.linkedin.com/in/asheshvashi>

---

From: Dave Page <[email-masked]>
Date: Tue, 9 Aug 2016 14:04:45 +0100

> Start a thread during the timeout?

Not necessarily. If we want a 2 second polling delay, we could just sleep
for 0.5 secs, collect messages, sleep for 0.5 sec, collect messages,
<repeat...> return to client.

---

From: Ashesh Vashi <[email-masked]>
Date: Tue, 9 Aug 2016 18:37:37 +0530

On Tue, Aug 9, 2016 at 6:34 PM, Dave Page <[email-masked]> wrote:

>
>
> On Tue, Aug 9, 2016 at 2:01 PM, Ashesh Vashi <
> [email-masked]> wrote:
>
That's a very huge delay in practical.
We were hardly waiting for during poll (that was in milliseconds), but -
still we were loosing a lot of the messages. (a lot more from the current
implementation).

--

Thanks & Regards,

Ashesh Vashi

---

From: Dave Page <[email-masked]>
Date: Tue, 9 Aug 2016 14:17:03 +0100

> still we were loosing a lot of the messages. (a lot more from the current

What was the original delay? Now there appears to be none at all.

---

From: Ashesh Vashi <[email-masked]>
Date: Tue, 9 Aug 2016 18:51:16 +0530

On Tue, Aug 9, 2016 at 6:47 PM, Dave Page <[email-masked]> wrote:

>
>
> On Tue, Aug 9, 2016 at 2:07 PM, Ashesh Vashi <
>>> Not necessarily. If we want a 2 second polling delay, we could just
>>> sleep for 0.5 secs, collect messages, sleep for 0.5 sec, collect messages,
That was 10 milliseconds.

--

Thanks & Regards,

Ashesh Vashi

---

From: Dave Page <[email-masked]>
Date: Tue, 9 Aug 2016 14:28:50 +0100

On Tue, Aug 9, 2016 at 2:21 PM, Ashesh Vashi <[email-masked]>
wrote:

> That was 10 milliseconds

Hmm, Ok - for some reason I thought it was much longer. Ignore that point
then :-)

---

From: Murtuza Zabuawala <[email-masked]>
Date: Tue, 16 Aug 2016 11:40:21 +0530

Hi Dave,

PFA patch with incremental messages.
RM#1523

Regards,
Murtuza

--
Regards,
Murtuza Zabuawala
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Tue, Aug 9, 2016 at 6:58 PM, Dave Page <[email-masked]> wrote:

>
>
> On Tue, Aug 9, 2016 at 2:21 PM, Ashesh Vashi <
>>>> We were hardly waiting for during poll (that was in milliseconds), but
>>>> - still we were loosing a lot of the messages. (a lot more from the current
>>>> implementation).
>>>>
>>>
index bb5c26b..6de42b0 100644
 
@@ -430,6 +432,10 @@ def poll(trans_id):
             status = 'Cancel'
             status = 'Busy'
+            if messages and len(messages) > 0:
+                result = ''.join(messages)
         status = 'NotConnected'
         result = error_msg
@@ -450,20 +456,25 @@ def poll(trans_id):
 
index 65647c1..f7f3358 100644
@@ -1286,7 +1286,9 @@ define(
 
                     // Enable/Disable query tool button only if is_query_tool is true.
@@ -1296,6 +1298,9 @@ define(
                     }
                   }
                   else if (res.data.status === 'Busy') {
+                    if (res.data.result) {
+                      self.update_msg_history(res.data.status, res.data.result, false);
+                    }
                     // If status is Busy then poll the result by recursive call to the poll function
                     self._poll();
                   }
@@ -1306,10 +1311,10 @@ define(
                       self.disable_tool_buttons(false);
                       $("#btn-cancel-query").prop('disabled', true);
                     }
-                    self.update_msg_history(false, res.data.result);
+                    self.update_msg_history(false, res.data.result, true);
                   }
                   else if (res.data.status === 'Cancel') {
-                    self.update_msg_history(false, "Execution Cancelled!")
+                    self.update_msg_history(false, "Execution Cancelled!", true)
                   }
                 },
                 error: function(e) {
@@ -1684,31 +1689,35 @@ define(
           if (clear_grid === undefined)
             clear_grid = true;
 
-          self.trigger('pgadmin-sqleditor:loading-icon:hide');
-          $("#btn-flash").prop('disabled', false);
-
-          $('.sql-editor-message').text(msg);
           self.gridView.messages_panel.focus();

+          if(status != 'Busy') {
+            self.trigger('pgadmin-sqleditor:loading-icon:hide');
+            });
+            self.gridView.history_collection.sort();
-          });
-
-          self.gridView.history_collection.sort();
         },
 
         // This function will return the total query execution Time.
@@ -2133,10 +2142,12 @@ define(
           var self = this;

 

         try:
+            self.__notices = []

---

From: Dave Page <[email-masked]>
Date: Tue, 16 Aug 2016 15:46:31 +0100

Hi

> PFA patch with incremental messages.

Can you rebase this please?

(pgadmin4)piranha:pgadmin4 dpage$ git apply
~/Downloads/RM_1523_with_incremental_msgs.patch
error: patch failed:
web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js:1296
error: web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js:
patch does not apply

Thanks.

---

From: Murtuza Zabuawala <[email-masked]>
Date: Tue, 16 Aug 2016 20:26:21 +0530

Hi Dave,

PFA updated patch.

 
 
index 2233586..913c3f5 100644
@@ -1291,7 +1291,9 @@ define(
 
                     // Enable/Disable query tool button only if is_query_tool is true.
@@ -1305,6 +1307,9 @@ define(
                     // If status is Busy then poll the result by recursive call to the poll function
                     self._poll();
                     is_query_running = true;
+                    if (res.data.result) {
+                      self.update_msg_history(res.data.status, res.data.result, false);
+                    }
                   }
                   else if (res.data.status === 'NotConnected') {
 
@@ -1313,10 +1318,10 @@ define(
@@ -1691,31 +1696,35 @@ define(

 
 
         // This function will return the total query execution Time.
@@ -2140,10 +2149,12 @@ define(
           var self = this;

 

         try:
+            self.__notices = []

---

From: Dave Page <[email-masked]>
Date: Wed, 17 Aug 2016 14:39:43 +0100

Hi

> PFA updated patch.

I just tested this, and found a number of issues:

- For a query like VACUUM FULL ANALYZE VERBOSE, the query runtime is
not displayed at the end of the messages. It is for SELECT queries
(note: pgAdmin 3 returns "Query returned successfully with no result
in 6.6 secs.").

- Messages seem to be duplicated. For example, the output from the
query above, run on pgAdmin3 is 95KB, whilst from pgAdmin4 it's
3.1MB(!). I believe it's because you're not clearing __notices in
messages(). I'm not entirely clear why that's even needed though -
can't we just return messages from self.conn.notices and clear that
directly?

- The messages div should scroll to the end as it's updated, per discussion.

Thanks.

---

From: Murtuza Zabuawala <[email-masked]>
Date: Thu, 18 Aug 2016 14:51:43 +0530

Hi Dave,

Please find updated patch with auto scrolling & also fixed duplicate
messages issue.
Please review.

Regards,
Murtuza

 
 
     return make_json_response(
         data={
diff --git a/web/pgadmin/tools/sqleditor/static/css/sqleditor.css b/web/pgadmin/tools/sqleditor/static/css/sqleditor.css
index 93c7921..84fbf1c 100644
--- a/web/pgadmin/tools/sqleditor/static/css/sqleditor.css
+++ b/web/pgadmin/tools/sqleditor/static/css/sqleditor.css
@@ -160,6 +160,9 @@
   font-family: monospace;
   padding-top: 5px;
   padding-left: 10px;
+  overflow: auto;
+  height: 100%;
+  font-size: 0.925em;
 }
 
 .limit-enabled {
diff --git a/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js b/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
index 2233586..297262f 100644
--- a/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
+++ b/web/pgadmin/tools/sqleditor/templates/sqleditor/js/sqleditor.js
@@ -1291,7 +1291,9 @@ define(
                     else {
                       // Show message in message and history tab in case of query tool
                       self.total_time = self.get_query_run_time(self.query_start_time, self.query_end_time);
-                      self.update_msg_history(true, res.data.result);
+                      var msg = S('{{ _('Query returned successfully in : %s.') }}').sprintf(self.total_time).value();
+                      res.data.result += "\n\n" + msg;
+                      self.update_msg_history(true, res.data.result, false);
                     }

@@ -1313,10 +1318,10 @@ define(
                       self.disable_tool_buttons(false);
                       $("#btn-cancel-query").prop('disabled', true);
                     }
-                    self.update_msg_history(false, res.data.result);
+                    self.update_msg_history(false, res.data.result, true);
                   }
                   else if (res.data.status === 'Cancel') {
-                    self.update_msg_history(false, "Execution Cancelled!")
+                    self.update_msg_history(false, "Execution Cancelled!", true)
                   }
                 },
                 error: function(e) {
@@ -1687,35 +1692,43 @@ define(
         // This function is used to raise appropriate message.
         update_msg_history: function(status, msg, clear_grid) {
           var self = this;
-
           if (clear_grid === undefined)
             clear_grid = true;

 
+          // Scroll automatically when msgs appends to element
+          setTimeout(function(){
+            $(".sql-editor-message").scrollTop($(".sql-editor-message")[0].scrollHeight);;
+          }, 10);
 
         // This function will return the total query execution Time.
@@ -2140,10 +2153,12 @@ define(
           var self = this;

index fbde603..05622e6 100644

 
         try:
+            self.__notices = []

     def status_message(self):
@@ -1094,7 +1077,10 @@ Failed to reset the connection to the server due to following error:
         """
         Returns the list of the messages/notices send from the database server.
         """
-        return self.conn.notices if self.conn else []
+        resp = []
+        while self.__notices:
+            resp.append(self.__notices.pop(0))
+        return resp

---

From: Dave Page <[email-masked]>
Date: Thu, 18 Aug 2016 17:08:59 +0100

Thanks, applied.