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: RESOLVED FIXED
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: Lionel Elie Mamane
URL:
Whiteboard: target:7.0.0
Keywords: haveBacktrace
Depends on:
Blocks: Database-Connectivity
  Show dependency treegraph
 
Reported: 2017-09-16 08:00 UTC by Robert Großkopf
Modified: 2020-05-11 10:07 UTC (History)
4 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 Großkopf 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 Großkopf 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 Großkopf 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 Großkopf 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.
Comment 26 Alex Thurgood 2019-12-02 11:23:41 UTC
(In reply to Julien Nabet from comment #25)
> (In reply to robert from comment #24)

> > ...
> > please have a look at comment14. I will see if I could test it again
> > tomorrow.



@Robert : can we close this now as fixed ?
Comment 27 Robert Großkopf 2019-12-02 15:21:57 UTC
(In reply to Alex Thurgood from comment #26)
> 
> @Robert : can we close this now as fixed ?

Have tested it again with the original description and LO 6.3.3.2 on OpenSUSE 15.1 64bit rpm Linux.
The behavior is the same: 
fist
CALL `AllNames`;
shows output
"-1 rows updated"
second
CALL `AllNames`;
doesn't give a result, shows status
"Commands out of sync; you can't run this command now"

If I try the same with PHPMyAdmin I get the resulte of the procedure, in this part the result of 
SELECT * FROM `NamesTest`;

So the bug is still there with the MySQL native connector.
Comment 28 Alex Thurgood 2019-12-02 17:03:44 UTC
Thanks Robert, lets keep it open then.
Comment 29 Julien Nabet 2019-12-02 20:57:52 UTC
On pc Debian x86-64 with master sources updated today, I could reproduce this.
Comment 30 Julien Nabet 2020-05-07 22:50:51 UTC
I gave a try with https://gerrit.libreoffice.org/c/core/+/93686

I just used https://dev.mysql.com/doc/refman/8.0/en/c-api-multiple-queries.html but don't know if it's the right thing to do.
Comment 31 Julien Nabet 2020-05-08 10:10:18 UTC
(In reply to Julien Nabet from comment #30)
> I gave a try with https://gerrit.libreoffice.org/c/core/+/93686
> 
> I just used
> https://dev.mysql.com/doc/refman/8.0/en/c-api-multiple-queries.html but
> don't know if it's the right thing to do.

Just for information, the patch was wrong, I abandoned it.
Comment 32 Lionel Elie Mamane 2020-05-09 12:57:26 UTC
(In reply to Julien Nabet from comment #31)
> Just for information, the patch was wrong, I abandoned it.

I was too perfectionist in my first reading. It solved the problem described here, but did not take the opportunity to improve mysql-sdbc to fix the "deep" underlying issue.
Comment 33 Commit Notification 2020-05-09 22:12:55 UTC
Lionel Elie Mamane committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/86c86719782243275b65f1f7f2cfdcc0e56c8cd4

tdf#112423: mysql-sdbc: implement XMultipleResults

It will be available in 7.0.0.

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

Affected users are encouraged to test the fix and report feedback.
Comment 34 Xisco Faulí 2020-05-11 06:44:53 UTC
Hi Lionel, Julien,
Do you think https://gerrit.libreoffice.org/c/core/+/93686 should be backported to 6.4 branch or better to wait for LibreOffice 7.0 ?
Comment 35 Lionel Elie Mamane 2020-05-11 07:50:39 UTC
To be honest, while it is a somewhat deeper change, of the "reorganise the code" kind, that always invites new bugs, I feel it is rather unlikely to introduce a regression. Famous last words before a brown paper bag moment...

Also, while doing that change, I was fixing / improving stuff left and right, that I was noticing reading the code. I haven't really tested it in isolation. I expect it wouldn't work well without also

commit 7c64b92665e13c1a09ee197bd36dac015989f00e

    mysql-sdbc: statement::execute do not handle parameters

but those two together "should" be sufficient for a backport.
Comment 36 Julien Nabet 2020-05-11 07:56:07 UTC
(In reply to Lionel Elie Mamane from comment #35)
> To be honest, while it is a somewhat deeper change, of the "reorganise the
> code" kind, that always invites new bugs, I feel it is rather unlikely to
> introduce a regression. Famous last words before a brown paper bag moment...
> 
> ...
Even if there are some lurking bugs, we may consider it won't be worse than now :-)
Comment 37 Xisco Faulí 2020-05-11 09:13:25 UTC
I tried to backport 86c86719782243275b65f1f7f2cfdcc0e56c8cd4 to libreoffice-6-4 but there were some conflicts and I don't feel confident enough to backport it myself.
@Lionel, would you mind doing it instead ? Otherwise, I guess it's better to wait for 7.0
Comment 38 Julien Nabet 2020-05-11 09:59:26 UTC
What about backporting the whole bunch of patches related to "mysql-sdbc", so 9 if I counted right?
Comment 39 Lionel Elie Mamane 2020-05-11 10:07:25 UTC
Some of these 9 are not justified to backport, since they improve code quality but are not (supposed to) change behaviour.

The conflicts in cherry-picking the "big" commit are probably / hopefully only from small stuff, and not from true logical dependencies on previous commits. Will take a look.