Bug 112423 - MySQL native connector "Commands out of sync..." when calling procedure second time. - Crash
Summary: MySQL native connector "Commands out of sync..." when calling procedure secon...
Status: REOPENED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Base (show other bugs)
Version:
(earliest affected)
5.4.1.2 release
Hardware: x86-64 (AMD64) All
: high major
Assignee: Not Assigned
URL:
Whiteboard: target:6.0.0 target:5.4.3
Keywords: haveBacktrace
Depends on:
Blocks:
 
Reported: 2017-09-16 08:00 UTC by robert
Modified: 2018-06-06 19:41 UTC (History)
3 users (show)

See Also:
Crash report or crash signature:


Attachments
Backtrace from lldb debug session (12.94 KB, text/plain)
2017-09-18 06:04 UTC, Alex Thurgood
Details

Note You need to log in before you can comment on or make changes to this bug.
Description robert 2017-09-16 08:00:01 UTC
I have tried to get the content, which should be shown after calling a stored procedure in MySQL/MariaDB. You could only get the content by macro, but the commands should work also without.

If you start Tools > SQL and write down
CALL `MyProcedureName`();
the command will be executed. If you do this the second time, the native Connector gives
"Commands out of sync; you can't run this command now"
You won't be able to see the content of any table afterwords. Base will be crashing.

If you try the same with JDBC-connector it will work and you could get the content of a procedure by macros.

Here a detailed description for testing:

You must have a MySQL or MariaDB database.
Connect to the database with the native connector
(https://extensions.libreoffice.org/extensions/mysql-native-connector)
Open Tools > SQL
and run the following command:

CREATE TABLE `NamesTest` (`ID` INT PRIMARY KEY, `name_last` VARCHAR(50), `name_first` VARCHAR(50));

Could be you have to run View > Refresh Tables after executing this command.

Now run the following commands, each separately:
-------

INSERT INTO `NamesTest` VALUES
(1, 'Burger', 'Mike'),
(2, 'Nice', 'Debby'),
(3, 'Miller', 'Arthur');

CREATE PROCEDURE `AllNames`()
BEGIN
SELECT * FROM `NamesTest`;
END

CALL `AllNames`;

CALL `AllNames`;

-------
The first CALL will work, the second runs out of sync.

Close Tools > SQL.
Try to open one of the tables for viewing the content.
Base and LO will crash.
Comment 1 Alex Thurgood 2017-09-18 05:53:43 UTC
Confirming with 

Version: 6.0.0.0.alpha0+
Build ID: ab65fe804cf3a97bd172b5551b553b9bcde6d756
CPU threads: 4; OS: Mac OS X 10.12.6; UI render: default; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group
Comment 2 Alex Thurgood 2017-09-18 06:03:49 UTC
The crash occurs here :

Process 93714 launched: '/Users/Shared/LO/core/instdir/LibreOfficeDev.app/Contents/MacOS/soffice' (x86_64)
Process 93714 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
    frame #0: 0x0000000103ca1206 libsvtlo.dylib`SvTreeListEntry::HasChildrenOnDemand(this=0x1110000000005618) const at treelistentry.cxx:216
   213 	
   214 	bool SvTreeListEntry::HasChildrenOnDemand() const
   215 	{
-> 216 	    return (bool)(nEntryFlags & SvTLEntryFlags::CHILDREN_ON_DEMAND);
   217 	}
   218 	
   219 	bool SvTreeListEntry::HasInUseEmphasis() const
Comment 3 Alex Thurgood 2017-09-18 06:04:36 UTC
Created attachment 136330 [details]
Backtrace from lldb debug session

Enclosed backtrace from lldb debug session
Comment 4 Lionel Elie Mamane 2017-09-20 05:06:27 UTC
Is the "show result of SELECT statements" checkbox checked?
Comment 5 Julien Nabet 2017-09-20 05:15:35 UTC
(In reply to Lionel Elie Mamane from comment #4)
> Is the "show result of SELECT statements" checkbox checked?

I got the same pb when checking this checkbox or not.
Comment 6 Alex Thurgood 2017-09-20 15:17:22 UTC
Me too, it was irrelevant whether that box was ticked or not, the result was the same message and then crash when attempting to open a table.
Comment 7 Julien Nabet 2017-09-20 19:04:29 UTC
Lionel: testing again calls to callstatements, it seems indeed more than 1 rs triggers pb.
Indeed, it fails here:
mariadb-connector-c/libmariadb/libmariadb.c
    557   if (mysql->status != MYSQL_STATUS_READY ||
    558       mysql->server_status & SERVER_MORE_RESULTS_EXIST)
    559   {
    560     SET_CLIENT_ERROR(mysql, CR_COMMANDS_OUT_OF_SYNC, unknown_sqlstate, 0);
    561     goto end;
    562   }
mysql->status is equal to MYSQL_STATUS_READY but I encountered the second condition.
Comment 8 Julien Nabet 2017-09-20 19:06:16 UTC
So 2 problems to fix:
1) the crash
2) the call to execute
Of course, fixing 2) should prevent from getting 1) but in any case, 1) shouldn't happen.
Comment 9 Julien Nabet 2017-09-20 20:11:25 UTC
Lionel, as you may have seen, I submitted https://gerrit.libreoffice.org/#/c/42564/ for review.
Comment 10 Commit Notification 2017-09-21 17:18:08 UTC
Julien Nabet committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=0297d9cc3b3fb990956cc2f8021a645d3c4fb86f

Related tdf#112423: avoid crash when calling procedure twice (dbaccess)

It will be available in 6.0.0.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 11 Commit Notification 2017-09-22 09:09:51 UTC
Julien Nabet committed a patch related to this issue.
It has been pushed to "libreoffice-5-4":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=52230cb62d2784a5e5eae6f9982a7d1b2d8e43e9&h=libreoffice-5-4

Related tdf#112423: avoid crash when calling procedure twice (dbaccess)

It will be available in 5.4.3.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 12 Julien Nabet 2017-09-24 08:54:36 UTC
Let's consider this one for crash only and so put this one to FIXED.
The related one has been fixed on master and waits for review on 5.4
Comment 13 Julien Nabet 2017-09-24 11:42:19 UTC
*** Bug 83995 has been marked as a duplicate of this bug. ***
Comment 14 robert 2017-09-25 19:21:24 UTC
I have tested with 
Version: 6.0.0.0.alpha0+
Build ID: 40892cd3311021c55e943228e16bfd36df7b1011
CPU threads: 4; OS: Linux 4.4; UI render: default; VCL: kde4; 
TinderBox: Linux-rpm_deb-x86_64@70-TDF, Branch:master, Time: 2017-09-25_01:20:06
Locale: de-DE (de_DE.UTF-8); Calc: group

Opened Tools > SQL
Run 
CALL `AllNames`;

Execute is pressed and then LO hangs.

Same with
CALL `AllNames`();

Procedure is running well with PHPMyAdmin and shows the result.

So I couldn't test the old bug, because the the command couldn't be executed any more. I will reopen the bug.
Comment 15 Julien Nabet 2017-09-25 19:33:17 UTC
I started from scratch (removed the table, the procedure then execute the steps), I don't reproduce this with master sources updated today :-(
When you say "run the following commands, each separately:", must I close Tools/sql direct after each command?
Comment 16 robert 2017-09-26 13:04:02 UTC
(In reply to Julien Nabet from comment #15)
> I started from scratch (removed the table, the procedure then execute the
> steps), I don't reproduce this with master sources updated today :-(
> When you say "run the following commands, each separately:", must I close
> Tools/sql direct after each command?

Hi Julien,

did you fix this bug in LO directly or did you fix the extension? I have installed the old extension, because I don't know where to get a new one.

I have only called the procedure I have created before I reported this bug.
Comment 17 Lionel Elie Mamane 2017-09-26 13:22:26 UTC
The "Commands out of sync; you can't run this command now" message has been fixed as bug 83995; there were changes both in LibreOffice itself and in the MySQL extension. According to Julien, this also works around the crash (by not putting MySQL in a situation where it gives that error).

For the crash part (that is, when MySQL gives that kind of error, LibreOffice crashes):
1) The "place of crash" from Alex doesn't make sense to me...
2) According to Julien, his patch (in LibreOffice itself, not the extension)
   fixes that crash. I didn't test that, but his patch looked very reasonable.
   (How it led to a crash is unclear to me.)
Comment 18 Julien Nabet 2017-09-26 14:02:37 UTC
Lionel: some details about the fix for the crash
Let's start from frame of the bt of this tdf:
    frame #3: 0x000000018521c305 libdbulo.dylib`dbaui::SbaTableQueryBrowser::implSelect(this=<unavailable>, _rDataSourceName=0x00007fff5fbfde48, _rCommand=<unavailable>, _nCommandType=0, _bEscapeProcessing=<unavailable>, _rxConnection=0x00007fff5fbfde00, _bSelectDirect=<unavailable>) at unodatbr.cxx:2458


2442          SvTreeListEntry* pCommand = getObjectEntry( _rDataSourceName, _rCommand, _nCommandType, &pDataSource, &pCommandType, true, _rxConnection );
2443  
2444          if (pCommand)
2445          {
2446              bool bSuccess = true;
2447              if ( _bSelectDirect )
2448              {
2449                  bSuccess = implSelect( pCommand );
2450              }
2451              else
2452              {
2453                  m_pTreeView->getListBox().Select( pCommand );
2454              }
2455  
2456              if ( bSuccess )
2457              {
2458                  m_pTreeView->getListBox().MakeVisible(pCommand);
2459                  m_pTreeView->getListBox().SetCursor(pCommand);
(see https://opengrok.libreoffice.org/xref/core/dbaccess/source/ui/browser/unodatbr.cxx#2442)


The pb of the crash was pCommand retrieved by getObjectEntry was not ok.
So the result was we entered in a catch in the method implSelect (line 2449) but the catch didn't set the return to false.
So LO went to line 2458 to execute MakeVisible and since this method needs a correct entry (so a correct pCommand), it crashed.

Unwinding to the getObjectEntry, I wanted to call ensureEntryObject before the if:
1200                      pObject = m_pTreeView->getListBox().GetEntryPosByName(sPath, pCommandType);
1201                      pCommandType = pObject;
1202                      if ( nIndex >= 0 )
1203                      {
1204                          if (ensureEntryObject(pObject))
1205                          {
(see https://opengrok.libreoffice.org/xref/core/dbaccess/source/ui/browser/unodatbr.cxx#1200)
since nIndex = -1 at this moment. Indeed we would have returned nullptr instead of an incorrect object. But then, even if there was no crash when opening the table, I hadn't the popup error "Commands out of sync; you can't run command now". So the cause of the empty table was unknown.
Comment 19 Alex Thurgood 2017-09-26 14:43:29 UTC
Confirming that this is fixed for me (as is the COMMAND OUT OF SYNC) problem with:


Version: 6.0.0.0.alpha0+
Build ID: 80d135922d5a5d0fd0d7178935653870cecf58ea
CPU threads: 4; OS: Mac OS X 10.12.6; UI render: default; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group
Comment 20 Alex Thurgood 2017-09-26 14:44:19 UTC
I am using the mysql native connector extension which I built at the same time as my master build.

For me, Julien's commits have fixed the problem.
Comment 21 Julien Nabet 2017-09-26 15:07:04 UTC
Lionel: just an hypothesis, since Robert uses the old extension perhaps this part doesn't work for him:
--- a/mysqlc/source/mysqlc_statement.cxx
+++ b/mysqlc/source/mysqlc_statement.cxx
@@ -175,7 +175,7 @@ Reference< XConnection > SAL_CALL OCommonStatement::getConnection()
 
 sal_Int32 SAL_CALL OCommonStatement::getUpdateCount()
 {
-    return 0;
+    return cppStatement->getUpdateCount();
 }
 
 Any SAL_CALL OStatement::queryInterface(const Type & rType)
@@ -238,9 +238,7 @@ sal_Bool SAL_CALL OCommonStatement::getMoreResults()
     MutexGuard aGuard(m_aMutex);
     checkDisposed(rBHelper.bDisposed);
 
-    // if your driver supports more than only one resultset
-    // and has one more at this moment return true
-    return false;
+    return cppStatement->getMoreResults();
 }

Of course, these methods are called from a try/catch but are the catches sufficient to deal with the lack of one (or both) of these methods in the extension?
Comment 22 Lionel Elie Mamane 2017-09-26 16:38:15 UTC
(In reply to Julien Nabet from comment #21)
> Lionel: just an hypothesis, since Robert uses the old extension perhaps this
> part doesn't work for him:

Yes, that seems probable.

> --- a/mysqlc/source/mysqlc_statement.cxx
> +++ b/mysqlc/source/mysqlc_statement.cxx

> Of course, these methods are called from a try/catch but are the catches
> sufficient to deal with the lack of one (or both) of these methods in the
> extension?

No, the try/catch deals with exceptions but here no exception is thrown by the buggy version.

The bug really was that the MySQL extension was _lying_. It said "yes, I support multiple results from one query (interface XMultipleResults)", but then it returned garbage data when one tried to use it. It should have either cleanly _not_ proposed the XMultipleResults interface *or* implement it correctly (which was very easy since MySQL Connector C++ implements it... maybe it didn't at the time this code was written. <shrug>).

The garbage data comes from a misunderstanding of the XMultipleResults interface. The person that wrote that probably thought that:

 - getMoreResults() returning false means "no next result available".
   That is wrong. It means "there is a next result, and the next result
   is an update count, not a resultset". A resultset = a sequence of rows of
   columns (like what a SELECT query returns).
 - getUpdateCount() returning zero is ... I don't know what he/she though.
   It means "the current result is an update count, and that count is zero,
   i.e. the UPDATE/DELETE/... changed zero rows, but otherwise was successfully
   executed". For a "shim" implementation it should have returned "-1", which
   means "the current result is not an update count.

So essentially, the old MySQL extension was causing an infinite loop in any caller that expected a correct XMultipleResults, since it was always saying "there is a next result giving an update count" and giving a valid value (zero) for the update count. While if it getMoreResults() returns false getUpdateCount returns -1, that is the signal for "there is no further result".
Comment 23 Julien Nabet 2018-06-06 19:23:51 UTC
Robert: why did you reopen the tracker?
Comment 24 robert 2018-06-06 19:38:27 UTC
(In reply to Julien Nabet from comment #23)
> Robert: why did you reopen the tracker?

Hi Julien,

please have a look at comment14. I will see if I could test it again tomorrow.
Comment 25 Julien Nabet 2018-06-06 19:41:26 UTC
(In reply to robert from comment #24)
> ...
> please have a look at comment14. I will see if I could test it again
> tomorrow.
Thank you for your quick feedback, I thought it was related to patch applied to extension or direct LO.