executeCommand: executes script twice?

General Discussion
1

Hi,

I have been using liquibase for a few months now and I am very happy and impressed, kudos.

I have run into my first problem. I need to execute an external script, so I have used the executeCommand directive. The problem is that the external script is getting executed twice. I have been doing tests for a while now and I have tried to reduce the problem to it’s minimum I can get to see if somebody can help me.

Here are the details:

joe@joeshome:a> ./liquibase --version
LiquiBase Version: 2.0-rc1

This is the changeset that is executing twice. The last one in the dbchanges file and the only one pending.

joe@joeshome:a> tail dbchanges.xml
  



  
    
 

This is the execphp script, a simple date command to a file:

date >> logs/$1.dt
joe@joeshome:a> ./liquibase updatesql
INFO 12/02/10 23:23:liquibase: Reading from `DATABASECHANGELOG`
INFO 12/02/10 23:23:liquibase: ChangeSet dbchanges.xml::2481::kikojover ran successfully in 2ms
INFO 12/02/10 23:23:liquibase: Successfully released change log lock
-- *********************************************************************
-- Update Database Script
-- *********************************************************************
-- Change Log: dbchanges.xml
-- Ran at: 12/02/10 23:23
-- Against: root@localhost@jdbc:mysql://localhost/vt_prodat
-- LiquiBase version: 2.0-rc1
-- *********************************************************************

-- Lock Database
-- Changeset dbchanges.xml::2481::kikojover::(Checksum: 2:aa39d71d2df7a3cb3fd3827e95bb6d3d)
-- ./execphp Add50SO.php;

INSERT INTO `DATABASECHANGELOG` (`AUTHOR`, `COMMENTS`, `DATEEXECUTED`, `DESCRIPTION`, `EXECTYPE`, `FILENAME`, `ID`, `LIQUIBASE`, `MD5SUM`, `ORDEREXECUTED`) VALUES ('kikojover', '', NOW(), 'Execute Shell Command', 'EXECUTED', 'dbchanges.xml', '2481', '2.0-rc1', '2:aa39d71d2df7a3cb3fd3827e95bb6d3d', 17);

-- Release Database Lock
INFO 12/02/10 23:23:liquibase: Successfully released change log lock

joe@joeshome:a> ./liquibase --logLevel=debug update
DEBUG 12/02/10 23:26:liquibase: Lock Database
INFO 12/02/10 23:27:liquibase: Successfully acquired change log lock
INFO 12/02/10 23:27:liquibase: Reading from `DATABASECHANGELOG`
INFO 12/02/10 23:27:liquibase:
INFO 12/02/10 23:27:liquibase:
DEBUG 12/02/10 23:27:liquibase: Running Changeset:dbchanges.xml::2481::kikojover::(Checksum: 2:aa39d71d2df7a3cb3fd3827e95bb6d3d)
DEBUG 12/02/10 23:27:liquibase: Changeset dbchanges.xml::2481::kikojover::(Checksum: 2:aa39d71d2df7a3cb3fd3827e95bb6d3d)
DEBUG 12/02/10 23:27:liquibase: Reading ChangeSet: dbchanges.xml::2481::kikojover::(Checksum: 2:aa39d71d2df7a3cb3fd3827e95bb6d3d)
INFO 12/02/10 23:27:liquibase:
INFO 12/02/10 23:27:liquibase:
DEBUG 12/02/10 23:27:liquibase: Shell command './execphp Add50SO.php' executed
INFO 12/02/10 23:27:liquibase: ChangeSet dbchanges.xml::2481::kikojover ran successfully in 38ms
DEBUG 12/02/10 23:27:liquibase: Release Database Lock
INFO 12/02/10 23:27:liquibase: Successfully released change log lock
LiquiBase Update Successful

Result of date in the logs file:

joe@joeshome:a/logs> cat Add50SO.php.dt
vie feb 12 23:27:03 CET 2010
vie feb 12 23:27:03 CET 2010

Any ideas where I should continue investigating?

Thanks
Joe
TSolucio

2

Thanks for the report, and the narrowing down of the problem.  I created an issue to track it better (http://liquibase.jira.com/browse/CORE-560) and will take a look at it.

Nathan