Broken PL/SQL snippets execute forever

[borisbrodski]

The bug

• Create a file with the content:

  BEGIN
  dbms_output.put_line('Test');
  a;
  END;
  /

• Put the cursor on the 'a' line and press <leader><ctrl>-2 to execute a query.

• IS: The query starts executing and executes for very long time. Message printed (counting seconds):

Query time: xx seconds

• EXPECTED: The query executes within milliseconds and produces the error message:

An error occurred when executing the SQL command:
BEGIN
    dbms_output.put_line('Starting ...');
    a;
END;

ORA-06550: line 3, column 5:
PLS-00201: identifier 'A' must be declared
ORA-06550: line 3, column 5:
PL/SQL: Statement ignored

    a;
    ^
1 statement failed.

Execution time: 0.06s

Further investigations

Ignoring the counting seconds message I tried to rerun the query multiple times. I got different results

• 1:

=SQL 4
Execution time: 0s

• 2:

=SQL 9
An error occurred when executing the SQL command:
-- @wbresult      a;
    a
Invalid SQL type: sqlKind = UNINITIALIZED
Execution time: 0s

• 3: The same message counting seconds

Restarting VIM (important) and rerunning the query but this time selecting everything in the file (ggVG <leader><ctrl>+2) delivered the desired results:

=SQL 3
An error occurred when executing the SQL command:
-- @wbresult BEGIN     dbms_output.put_line('Starting ...');     a; END; / ;
BEGIN
    dbms_output.put_line('Starting ...');
    a;
END;
ORA-06550: line 4, column 5:
PLS-00201: identifier 'A' must be declared
ORA-06550: line 4, column 5:
PL/SQL: Statement ignored
-- @wbresult BEGIN     dbms_output.put_line('Starting ...');     a; END; / ;
BEGIN
    dbms_output.put_line('Starting ...');
    a;
END;
                                                                                                                                                                                                              ^
Execution time: 0.07s

Conclusion

I think, the problem is somewhere in the detection of the PL/SQL block boundaries.
But the actual bug is, that even if the boundaries are wrong and a peace of junk
was send for execution, the plugin should not hang (counting seconds) but provide
some error message.

Also there should be an official way of canceling the current running query, if the execution
indeed takes longer, as expected.

[cosminadrianpopescu]

IS: The query starts executing and executes for very long time. Message printed (counting seconds):

I don't know why you don't have any result. I've tried to reproduce and I always have a result. So, I don't have vim hanging. Could you please check the logs, when VIM is hanging to see what is begin sent to the server. The log is located at <g:sw_tmp>/<v:servername>-<filename-with-dash-instead-of-point>.

In the above mentioned file you should see what the plugin sent to the SQL Workbench/J.

Ignoring the counting seconds message I tried to rerun the query multiple times. I got different results

This I could reproduce, but it looks like a problem with SQL Workbench/J, as you can see from my logs:

> ..> -- @wbresult   BEGIN dbms_output.put_line('Test'); a; END; /


BEGIN
dbms_output.put_line('Test');
a;
END;
/..> ..> ..> ..> ..> ..> ..> Execution time: 0s

As you can see, The servers retrieves the proper query, but instead of the error message it returns directly without any output.

Restarting VIM (important) and rerunning the query but this time selecting everything in the file (ggVG +2) delivered the desired results:

If you select the full sql, then the plugin will send the proper data to the SQL Workbench/J and everything works as expected. If you just do ctrl+2, then the default delimiter is used to split the statements, which is ; and it will only send the query a; to the Workbench instance.

To work-around this, you can set the b:delimiter variable in the sql buffer to /. Then it will be interpreted properly. I will add a command to to that, something like SWSqlSetDelimiter.

The default delimiter (b:delimiter) is set to ;.

[borisbrodski]

To gain a better overview I deleted all tmp files, restartet vim and tried my example one more time. But this time it doesn't hang... Could the problem has hidden in my deleted tmp files?

Now in my tmp directory I just have GVIM-8 (1M) and row-GVIM (1K). The name of the SQL-file, that is connected to the DB is exception-test.sql. So no <g:sw_tmp>/<v:servername>-<filename-with-dash-instead-of-point> file is there. This file was also not present before I deleted everything in the directory.

Btw. (Offtopic): Is it possible somehow to see the output of dbms_output.put_line? The standard set serveroutput on is not helping here. (This work with the SQL-Workbench GUI)

[cosminadrianpopescu]

To gain a better overview I deleted all tmp files, restartet vim and tried my example one more time. But this time it doesn't hang... Could the problem has hidden in my deleted tmp files?

Normally that is just logging. Nothing is read from there. Maybe if the OS had a problem writing to those file, then VIM would have to wait for that (being single threaded)

Now in my tmp directory I just have GVIM-8 (1M) and row-GVIM (1K). The name of the SQL-file, that is connected to the DB is exception-test.sql. So no <g:sw_tmp>/<v:servername>- file is there. This file was also not present before I deleted everything in the directory.

Sorry. I forgot to mention. You have to activate it (the logging). Set 'g:sw_log_to_file` to 1, then restart VIM.

Btw. (Offtopic): Is it possible somehow to see the output of dbms_output.put_line? The standard set serveroutput on is not helping here. (This work with the SQL-Workbench GUI)

I am seeing the output without problems, after sending these queries:

set serveroutput on;
wbcall dbms_output.enable;

This should work.

[borisbrodski]

Thank you for the quick response. dbms_output works now even after restarting VIM without any set serveroutput on or wbcall dbms_output.enable;. Then it stops working again... Very strange.

There must be some bug though. The execution of the PL/SQL runs always differently. (Occasionally correct).

I tried to execute a slightly larger PLSQL multiple times and also to enable dbms_output. I also executed broken SQL (just one line of the script). Most of the time I got execution time: 0s and it looks, like in this case nothing gets executed. But sometimes I get the correct output with execution time > 0.

Ones after executing

set serveroutput on;
wbcall dbms_output.enable;

VIM appeared to hang counting seconds. But after 1 minute it outputs the desired result. Here is the log:

MYDB> MYDB> -- @wbresult set serveroutput on; wbcall dbms_output.enable; 
set serveroutput on;
wbcall dbms_output.enable;
..> 
Execution time: 0s
MYDB> -- @wbresult set serveroutput on; wbcall dbms_output.enable; 
set serveroutput on;
wbcall dbms_output.enable;

dbms_output.enable executed successfully

Execution time: 51.34s
MYDB> MYDB> ..> 
Execution time: 0s
MYDB> 
dbms_output.enable executed successfully

Execution time: 2.25s
MYDB> MYDB>

Note 51.34s!

Also I found, that after selecting multiple lines and executing those with <leader><ctrl+2> I get sometimes

10 lines yanked
"~/.cache/sql-workbench/tmp/row-GVIM" [CR missing] 145L, 4244C

and after pressing ENTER the execution starts and then it works! But most of the time I get no such output. The execution starts immediately and then it doesn't work with execution time: 0s

[cosminadrianpopescu]

Thank you for the quick response. dbms_output works now even after restarting VIM without any set serveroutput on or wbcall dbms_output.enable;. Then it stops working again... Very strange.

What I do, is set it (the dbms_output.enable) in the connect scripts in the conection window in the SQL Workbench/J. This way, I don't have to worry about it. And it works without any issue. It's true, that it takes a little more time to connect to the profile, but for me it's ok like this.

VIM appeared to hang counting seconds. But after 1 minute it outputs the desired result. Here is the log:

Could you please also try this in the GUI of SQL Workbench. If it has the same behavior, then there is nothing I can do. It's a problem with SQL Workbench/J. If there it works as expected every time (no hangs, no output missing), then could you please tail the log file and see if you get the response immediately?

But I would say (judging by your log), that the problem is with the SQL Workbench/J. This is because the execution time, is always returned by the SQL Workbench/J, not by the plugin.

Even more, you can run SQL Workbench/J in console mode (see here: http://www.sql-workbench.net/manual/console-mode.html) and check out the behaviour.

and after pressing ENTER the execution starts and then it works! But most of the time I get no such output. The execution starts immediately and then it doesn't work with execution time: 0s

Same thing: Could you check the log and see what happens?

Thank you.

[cosminadrianpopescu]

The plugin, runs in the background an SQL workbench/J in console mode and then acts like a bridge between this instance and the vim instance. So if there is a bug in SQL Workbench/J there are not many things that I can fix.

[borisbrodski]

I had the long counting seconds again. I send broken SQL dbms_output.put_line('Start'); to the DBMS and it hangs now. Here is the log:

....
;..> ..> ..> ..> ..> ..> ..> ..> ..> 
Execution time: 0s
MYDB> MYDB> ..> -- @wbresult BEGIN     dbms_output.put_line('Start');
BEGIN
    dbms_output.put_line('Start');..> ..> ..>

UPDATE:
After a more then a minute, the counting stopped. The log looks like this now:

;..> ..> ..> ..> ..> ..> ..> ..> ..> 
Execution time: 0s
MYDB> MYDB> ..> -- @wbresult BEGIN     dbms_output.put_line('Start');
BEGIN
    dbms_output.put_line('Start');..> ..> ..> 
To view table and column comments, the property 'remarksReporting' should be set to 'true' in the connection profile.

109 objects written to C:\Users\MyUser\.cache\sql-workbench\tmp\GVIM-36
XSLT transformation into C:\Users\MyUser\.cache\sql-workbench\MYDB.vim finished successfully.

Execution time: 2m 30s
MYDB>

[borisbrodski]

Ok, it looks, that the finished report saved me last time from hanging forever. Now as I send BEGIN it hangs forever (currently 2900 seconds)

Log:

;..> ..> ..> ..> ..> ..> ..> ..> ..> 
Execution time: 0s
MYDB> MYDB> ..> -- @wbresult BEGIN ;
BEGIN
;..> ..> ..> 

[cosminadrianpopescu]

I had the long counting seconds again. I send broken SQL dbms_output.put_line('Start'); to the DBMS and it hangs now. Here is the log:

Checking the log here, it seems that the delimiter is not sent to the server. Do you have a reproductible scenario? Do you know exactly what select you've send and in which context? Because if I just do <leader><C-Space>, for me is fine.

Ok, it looks, that the finished report saved me last time from hanging forever. Now as I send BEGIN it hangs forever (currently 2900 seconds)

Could you please also check in the console version of SQL Workbench/J? If nothing happens there, then there is not much I can do. Also, when you say it hangs, it's VIM that hangs or a result which is not returned (meaning that you can still use vim, but the query time keeps going and no result is returned)? If this is the case, try sending another query after and post the log.

VIM appeared to hang counting seconds. But after 1 minute it outputs the desired result. Here is the log:

Again, could you please check in the console version of SQL Workbench/J. I have no problems executing the 2 queries. And as I was saying, I execute them daily, when I connect to the profile (they are in the Connection scripts and are executed automatically by SQL Workbench/J)

After a more then a minute, the counting stopped. The log looks like this now:

I am not sure I understand exactly what you mean here.

[borisbrodski]

I will do it later on. One quick note: if I select a part of SQL the delimiter is not always selected. ExecuteSelected (which I vmap to ctrl+space) doesn't add delimiter if it is not present. Right?

[borisbrodski]

Ok, if I select a line with just a single word BEGIN and send it to the SQL Workbench/J using SWSqlExecuteSelected, you send the following to the console client:

-- @wbresult BEGIN ;
BEGIN
;

In the log file it looks like this:

MYDB> MYDB> ..> -- @wbresult BEGIN ;
BEGIN
;..> ..> ..>

I simulated it with the console and was indeed able to reproduce the problem:

MYDB> -- @wbresult sdjklfh
..> BEGIN
..> ;
..>

It turns out, that if you send BEGIN, the ; doesn't terminate the statement any more. You need to send / on a extra line to terminate such statement (continue the last listing sending / to the DBMS):

MYDB> -- @wbresult sdjklfh
..> BEGIN
..> ;
..> /
An error occurred when executing the SQL command:
-- @wbresult sdjklfh
BEGIN
;


ORA-06550: line 3, column 1:
PLS-00103: Encountered the symbol ";" when expecting one of the following:

   ( begin case declare exit for goto if loop mod null pragma
   raise return select update while with <an identifier>
   <a double-quoted delimited-identifier> <a bind variable> <<
   continue close current delete fetch lock insert open rollback
   savepoint set sql execute commit forall merge pipe purge

-- @wbresult sdjklfh
BEGIN
;

[cosminadrianpopescu]

I've created #32 and #33

Do you think we can close this one?

[borisbrodski]

And #34. Yes.