Adventures in ACFS 12c (the end result is worth the painful journey)



After a basic trail had proved that snapshot clones on ACFS seemed to work for a very small database we decided that we could possible use this as a solution to very quickly provision new test environments and save a huge amount of disk space in the process.
To give you some idea of the scale of the issue, we have 74 (yes 74) test environments each of which is 300GB - so doing some simple maths means we have a lot of storage. Each time we copy it, even with out improved TTS method it still takes a few hours and is very tedious work (scripting of it is also in progress to improve that)
 To check that the new ACFS snapshot clone could cope with data of this size and to see how quickly environments could be created i went ahead and build a new test environment - here is the tale of woe (and joy) of what happened.
Right beginning at the start (which is always a good idea)
 Let's see what disks we have available to ASM (s is an alias for sqlplus / as sysdba by the way)
[oracle@server]:+ASM:[~]# s

SQL*Plus: Release 12.1.0.1.0 Production on Thu Nov 28 08:57:20 2013
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Automatic Storage Management option

SQL> select path, group_number group_#, disk_number disk_#, mount_status,
       header_status, state, total_mb, free_mb
from v$asm_disk;
PATH
--------------------------------------------------------------------------------
   GROUP_#     DISK_# MOUNT_S HEADER_STATU STATE      TOTAL_MB    FREE_MB
---------- ---------- ------- ------------ -------- ---------- ----------
/dev/raw/raw3
         0          0 CLOSED  CANDIDATE    NORMAL            0          0
/dev/raw/raw4
         0          1 CLOSED  CANDIDATE    NORMAL            0          0
/dev/raw/raw2
         1          0 CACHED  MEMBER       NORMAL        10000       2838
/dev/raw/raw1
         1          1 CACHED  MEMBER       NORMAL        13994       6832

So we have 4 disks in total - 2 of which are candidates. Let's create a new diskgroup with external redundancy (the are raid 5 on the san/disk array).
SQL> create diskgroup endur_dg external redundancy disk '/dev/raw/raw3' ;
create diskgroup endur_dg external redundancy disk '/dev/raw/raw3'
*
ERROR at line 1:
ORA-15260: permission denied on ASM disk group
SQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Automatic Storage Management option
You have new mail in /var/mail/oracle

OK - schoolboy error number one - you have to be sysasm to do this now.
[oracle@server]:+ASM:[~]# sqlplus / as sysasm
SQL*Plus: Release 12.1.0.1.0 Production on Thu Nov 28 09:15:44 2013
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Automatic Storage Management option
SQL>  create diskgroup endur_dg external redundancy disk '/dev/raw/raw3' ;
Diskgroup created.
OK diskgroup created - lets add another disk to it.
SQL> alter diskgroup endur_dg add disk '/dev/raw/raw4';
Diskgroup altered.

At this point i realised that when i asked the unix team to remove two ext3 filesystems and create 2 raw volumes with the space that the original ext volume group was made up of multiple luns. I then got them to allocate all the luns as raw devices to give me the original space i asked for.
OK - looking good so far - now we need to create a volume to be used to run out acfs filesystem out of

SQL> ALTER DISKGROUP ENDUR_DG ADD VOLUME ENDUR_ACFS_VOL SIZE 400G;
ALTER DISKGROUP ENDUR_DG ADD VOLUME ENDUR_ACFS_VOL SIZE 400G
*
ERROR at line 1:
ORA-15032: not all alterations performed
ORA-15221: ASM operation requires compatible.asm of 11.2.0.0.0 or higher
OK - easily changed
SQL> alter diskgroup ENDUR_DG set attribute 'compatible.asm'='11.2';
Diskgroup altered.
SQL>  ALTER DISKGROUP ENDUR_DG ADD VOLUME ENDUR_ACFS_VOL SIZE 400G;
 ALTER DISKGROUP ENDUR_DG ADD VOLUME ENDUR_ACFS_VOL SIZE 400G
*
ERROR at line 1:
ORA-15032: not all alterations performed
ORA-15474: volume name is greater than 11 characters

OK.... again easily changed
SQL>  ALTER DISKGROUP ENDUR_DG ADD VOLUME ENDUR_VOL SIZE 400G;
Diskgroup altered.
SO now we have out volume - lets have a look in V$ASM_VOLUME

SQL> SELECT * from v$ASM_VOLUME;
           2 ENDUR_VOL                            33554433     409600             1 UNPROT              4            128 ENABLED          256   832676813               0             32          
/dev/asm/endur_vol-273
         0

Here we can see it has create the device file /dev/asm/endur_vol-273 - we now need to use this for the next stage. Lets create a filesystem on it using mkfs
[oracle@server]:+ASM:[~]# /sbin/mkfs -t acfs /dev/asm/endur_vol-273
mkfs.acfs: version                   = 12.1.0.1.0
mkfs.acfs: on-disk version           = 39.0
mkfs.acfs: volume                    = /dev/asm/endur_vol-273
mkfs.acfs: volume size               = 429496729600
mkfs.acfs: Format complete.
[oracle@server]:+ASM:[~]#

Ok that's formatted fine, we can see it's 400GB roughly. Now we create a mount point for the filesystem to be attached to
[oracle@server]:+ASM:[~]# mkdir /oracle/ENDUR-ACFS
Now we mount the acfs filesystem to that directory
[oracle@server]:+ASM:[~]# /bin/mount -t acfs /dev/asm/endur_vol-273 /oracle/ENDUR-ACFS
mount: only root can do that
Or we get the unix team to do it for us.....
So now we have a filesystem that looks like any other and is displayed in df -k
Filesystem                                         1K-blocks       Used Available Use% Mounted on
/dev/asm/endur_vol-273                             367001600  330258580  36743020  90% /oracle/ENDUR-ACFS

AT this point ACFS is all up and working and we can create files in that filesystem much like any other (as long as the unix team change permissions on it which they always forget....)
Now lets begin with the main test - lets create a new database on the new ACFS filesystem from the SEED
Lets have a look at the names of the current files - they are all residing on the original first ACFS filesystem i created.
SQL> select name from v$datafile;
NAME
--------------------------------------------------------------------------------
/oracle/ASCF/ENDCON/datafile/o1_mf_system_98st24v8_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_sysaux_98ssz5qd_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_undotbs1_98st553x_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_system_98st6mg0_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_users_98st540q_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_sysaux_98st6mcy_.dbf

6 rows selected.

So lets create a normal copy of the database usin the new syntax
SQL> CREATE PLUGGABLE DATABASE ENDUR01 FROM PDB$SEED
  FILE_NAME_CONVERT=('/oracle/ASCF','/oracle/ENDUR-ACFS');  2
CREATE PLUGGABLE DATABASE ENDUR01 FROM PDB$SEED
                          *
ERROR at line 1:
ORA-65000: missing or invalid pluggable database name

OK guessing the syntax didn't work - lets guess again
SQL>  CREATE PLUGGABLE DATABASE ENDUR01  FILE_NAME_CONVERT=('/oracle/ASCF','/oracle/ENDUR-ACFS');
 CREATE PLUGGABLE DATABASE ENDUR01  FILE_NAME_CONVERT=('/oracle/ASCF','/oracle/ENDUR-ACFS')
ERROR at line 1:
ORA-00922: missing or invalid option

Still didn't work - lets read the manual.
SQL> CREATE PLUGGABLE DATABASE ENDUR01 admin user pdb_admin identified by oracle FILE_NAME_CONVERT=('/oracle/ASCF','/oracle/ENDUR-ACFS')
  2  /
CREATE PLUGGABLE DATABASE ENDUR01 admin user pdb_admin identified by oracle FILE_NAME_CONVERT=('/oracle/ASCF','/oracle/ENDUR-ACFS')
*
ERROR at line 1:
ORA-01276: Cannot add file
/oracle/ENDUR-ACFS/ENDCON/datafile/o1_mf_system_98st6mg0_.dbf.  File has an
Oracle Managed Files file name.

Ok getting better - past the syntax problems at least
SQL> sho parameter create
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
create_bitmap_area_size              integer     8388608
create_stored_outlines               string
db_create_file_dest                  string      /oracle/ASCF
db_create_online_log_dest_1          string
db_create_online_log_dest_2          string
db_create_online_log_dest_3          string
db_create_online_log_dest_4          string
db_create_online_log_dest_5          string


Lets change db_create_file_dest to be on the new ACFS fileystem
SQL> alter system set db_create_file_dest='/oracle/ENDUR-ACFS';
System altered.
SQL> set timing on
SQL> CREATE PLUGGABLE DATABASE ENDUR01 admin user pdb_admin identified by oracle;

Pluggable database created.

Elapsed: 00:00:03.08

ANd there we go - a new database ENDUR01 as a copy of the seed in 3 secs (and that is a straight copy no snapshots or anything here)
We can see the new files now:
SQL> select name from v$datafile;
NAME
--------------------------------------------------------------------------------
/oracle/ASCF/ENDCON/datafile/o1_mf_system_98st24v8_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_sysaux_98ssz5qd_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_undotbs1_98st553x_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_system_98st6mg0_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_users_98st540q_.dbf
/oracle/ASCF/ENDCON/datafile/o1_mf_sysaux_98st6mcy_.dbf
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_system
_99gm7pxp_.dbf
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_sysaux
_99gm7pxp_.dbf

8 rows selected.

Elapsed: 00:00:00.00

Lets see the files which are just for ENDUR01
SQL> alter session set container=ENDUR01;
Session altered.
Elapsed: 00:00:00.00
SQL> select name from v$datafile;
NAME
--------------------------------------------------------------------------------
/oracle/ASCF/ENDCON/datafile/o1_mf_undotbs1_98st553x_.dbf
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_system
_99gm7pxp_.dbf
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_sysaux
_99gm7pxp_.dbf
Elapsed: 00:00:00.01

SO we see system/sysaux that were copied and undo which is shared between all PDB's
So lets create a new tablespace to hold all the new data i want to import
SQL> create tablespace endur;
create tablespace endur
*
ERROR at line 1:
ORA-01109: database not open

Or let's not...
Right let's open it - switch back to CDB
SQL> alter session set container=CDB$ROOT;
SQL> alter pluggable database endur01 open;
Pluggable database altered.
SQL>  create tablespace endur ;
Tablespace created.
Elapsed: 00:00:00.2

And add lots of files
SQL> alter tablespace endur add datafile; (x10)
Now lets create a local user in ENDUR01 that we can use to import the data.
SQL> create user pumpy identified by pumpy;
User created.
Elapsed: 00:00:00.03
SQL> grant dba to pumpy;
Grant succeeded.
Lets create a directory for datapump to use,
SQL> create directory scratch as '/scratch';
Directory created.
Elapsed: 00:00:00.09

Now lets import the data (which is split over 6 files - created with adv compression to keep the size down)
Here is the parfile
directory=SCRATCH dumpfile=exportdp-ENDUR01_file%U_of_6.dmp schemas=ENDUR01 remap_tablespace=ENDUR01:ENDUR remap_schema=ENDUR01:ENDUR TRANSFORM=SEGMENT_ATTRIBUTES:n:table logfile=acfs_import.logTABLE_EXISTS_ACTION=REPLACE PARALLEL=6
Lets check we can connect to the new PDB (remember this has to be through sqlnet)
[oracle@server]:ENDCON:[/scratch]# tnsping endur01
TNS Ping Utility for Linux: Version 12.1.0.1.0 - Production on 28-NOV-2013 14:14:43
Copyright (c) 1997, 2013, Oracle.  All rights reserved.
Used parameter files:
/oracle/12.0.0.1/network/admin/sqlnet.ora
Used TNSNAMES adapter to resolve the alias
Attempting to contact (DESCRIPTION = (ADDRESS = (PROTOCOL = TCP)(HOST = server.e-ssi.net)(PORT = 1531)) (CONNECT_DATA = (SERVER = DEDICATED) (SERVICE_NAME = ENDUR01)))
OK (0 msec)

We can reach it OK (i had earlier manually added this to tnsnames.ora - this will not happen automatically when a PDB is added, only the listener registration of the new service is automatic)
Right lets import
[oracle@server]:ENDCON:[/scratch]# impdp pumpy/pumpy@endur01 parfile=acfs.par
Import: Release 12.1.0.1.0 - Production on Thu Nov 28 14:15:35 2013
Copyright (c) 1982, 2013, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
ORA-39002: invalid operation
ORA-31694: master table "PUMPY"."SYS_IMPORT_SCHEMA_01" failed to load/unload
ORA-31640: unable to open dump file "/scratch/exportdp-ENDUR01_file01_of_6.dmp" for read
ORA-19505: failed to identify file "/scratch/exportdp-ENDUR01_file01_of_6.dmp"
ORA-17503: ksfdopn:3 Failed to open file /scratch/exportdp-ENDUR01_file01_of_6.dmp
ORA-17500: ODM err:Operation not permitted

That's not a good start....
Quick google and this is nfs related (which is where i put the dump files) - quick permissions check
[oracle@server]:ENDCON:[~]# cd $ORACLE_HOME/bin
[oracle@server]:ENDCON:[/oracle/12.0.0.1/bin]# ls -l oradism
-rwsr-x--- 1 root oinstall 105070 May 24  2013 oradism

That looks OK. At this point  gave up as i was wasting time (it's probably because i switched on direct nfs but the nfs share wasn't set up quite right)
I moved the files to a normal ext3 filesystem, lets recreate the directory object
SQL*Plus: Release 12.1.0.1.0 Production on Thu Nov 28 14:26:21 2013
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Advanced Analytics
and Real Application Testing options
SQL> drop directory scratch;
drop directory scratch
*
ERROR at line 1:
ORA-04043: object SCRATCH does not exist

aargh - switch containers first - this is going to take some getting used to....
SQL> alter session set container=ENDUR01;
Session altered.
SQL> drop directory scratch;
Directory dropped.
SQL>
SQL> create directory scratch as '/oracle/EDPM/oradata/ACFSTEST';
Directory created.

Right import again...
[oracle@server]:ENDCON:[/scratch]# impdp pumpy/pumpy@endur01 parfile=acfs.par
And we wait (normally this takes 5.5 hours) but after 3.5 hours it's already finished with no problems - this is looking very good..... There were many differences though to the original system so it's not very scientific and we can;t say ACFS is amazingly fast - but we can say it's not stupidly slow.....
quick aside here - datapump now shows elapsed time at the end of the log which is nice:
Job "PUMPY"."SYS_IMPORT_SCHEMA_01" completed with 0 error(s) at Thu Nov 28 18:52:02 2013 elapsed 0 03:38:02
Right lets see how much space it used
[oracle@server]:ENDCON:[/scratch]# s
SQL*Plus: Release 12.1.0.1.0 Production on Thu Nov 28 19:25:38 2013
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Advanced Analytics
and Real Application Testing options

SQL> sho pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED
---------- ------------------------------ ---------- ----------
         2 PDB$SEED                       READ ONLY  NO
         3 ENDUR01                        READ WRITE NO
SQL> alter session set container=ENDUR01;
Session altered.
SQL> select sum(bytes)/(1024*1024) from v$datafile;
               301425

So roughly 300GB - same as normal as expected.
Let's start the snapshot clone of this database now. First we need to close it and open it read only.
SQL> alter session set container=CDB$ROOT;
Session altered.
SQL> alter pluggable database endur01 close;
Pluggable database altered.
SQL> alter pluggable database endur01 open read only;
Pluggable database altered.
SQL>

Lets see how much space is used at the moment
SQL> !df -k |grep ENDUR
/dev/asm/endur_vol-273                             419430400  326077560  93352840  78% /oracle/ENDUR-ACFS
SQL> !df -h |grep ENDUR
/dev/asm/endur_vol-273                             400G  311G   90G  78% /oracle/ENDUR-ACFS

Right lets give it a go
SQL> create pluggable database endur02 from endur01 snapshot copy;
create pluggable database endur02 from endur01 snapshot copy
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level
ORA-17517: Database cloning using storage snapshot failed on file :
Elapsed: 00:00:00.65
SQL>

Not good - lets check the alert log
2013-11-28 19:30:49.325000 +00:00
create pluggable database endur02 from endur01 snapshot copy
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p000_15074.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p008_15090.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p001_15076.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p006_15086.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p00a_15094.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p004_15082.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p007_15088.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p005_15084.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p003_15080.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p009_15092.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p00b_15096.trc:
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p002_15078.trc:
ORA-604 signalled during: create pluggable database endur02 from endur01 snapshot copy...

Lots of errors - lets check one of the traces
*** 2013-11-28 19:30:49.894
*** SESSION ID:(305.1431) 2013-11-28 19:30:49.894
*** SERVICE NAME:(SYS$USERS) 2013-11-28 19:30:49.894
*** MODULE NAME:(sqlplus@server (TNS V1-V3)) 2013-11-28 19:30:49.894
*** ACTION NAME:() 2013-11-28 19:30:49.894
*** CONTAINER ID:(1) 2013-11-28 19:30:49.894

snapshot is not supported because Oracle ADVM low
Cloning an ACFS volume failed for file:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_system_99gm7pxp_.dbf

Now i had that on my last attempt at ACFS and it seems to be something to do with not enough space somewhere - not sure if it's ACFS volume or diskgroup.
Lets shrink acfs a bit to give the diskgroup back some room

[oracle@server]:ENDCON:[/scratch]# /sbin/acfsutil size 350G /oracle/ENDUR-ACFS
acfsutil size: new file system size: 375809638400 (358400MB)
Let's also make sure compatible is 12.1 for this new stuff in ASM
SQL> ALTER DISKGROUP ENDUR_DG SET ATTRIBUTE 'compatible.asm' = '12.1.0.0';
Diskgroup altered.
SQL> ALTER DISKGROUP ENDUR_DG SET ATTRIBUTE 'compatible.rdbms' = '12.1.0.0';
Diskgroup altered.
SQL> ALTER DISKGROUP ENDUR_DG SET ATTRIBUTE 'compatible.advm' = '12.1.0.0';
Diskgroup altered.
SQL>

Now lets bounce the db instance and try again
SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area 3.0398E+10 bytes
Fixed Size                  2699368 bytes
Variable Size            3288338328 bytes
Database Buffers         2.7045E+10 bytes
Redo Buffers               62296064 bytes
Database mounted.
Database opened.
SQL> sho pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED
---------- ------------------------------ ---------- ----------
         2 PDB$SEED                       READ ONLY  NO
         3 ENDUR01                        MOUNTED

We need to open the database again - this is not automatic after restart
SQL> alter pluggable database endur01 open read only;
Pluggable database altered.
Elapsed: 00:00:00.86
SQL>
Elapsed: 00:00:00.86

Let's try again
SQL>  create pluggable database endur02 from endur01 snapshot copy;
 create pluggable database endur02 from endur01 snapshot copy
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level
ORA-17517: Database cloning using storage snapshot failed on file :
Elapsed: 00:00:00.41
SQL>

Not looking good - that's the same error
but in alert log we have...it's different

 create pluggable database endur02 from endur01 snapshot copy
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p008_30231.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkrm4_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p007_30229.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkslm_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p009_30233.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkr1d_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p004_30222.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkw3m_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p006_30226.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmktho_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p005_30224.trc:
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkvb7_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101
Errors in file /oracle/diag/rdbms/endcon/ENDCON/trace/ENDCON_p002_30218.trc:

Checking the trace again and it doesn;t really help
*** 2013-11-28 19:45:28.398
*** SESSION ID:(127.47) 2013-11-28 19:45:28.398
*** CLIENT ID:() 2013-11-28 19:45:28.398
*** SERVICE NAME:(SYS$USERS) 2013-11-28 19:45:28.398
*** MODULE NAME:(sqlplus@server (TNS V1-V3)) 2013-11-28 19:45:28.398
*** ACTION NAME:() 2013-11-28 19:45:28.398
*** CONTAINER ID:(1) 2013-11-28 19:45:28.398


Additional information: 101
failed to link target:/oracle/ENDUR-ACFS/ENDCON/EC43AD3246C35EA1E0430200007F774F/datafile/o1_mf_endur_99hbcjnq_.dbf to clone:/oracle/ENDUR-ACFS/.ACFS/snaps/EC43AD3246C35EA1E0430200007F774F/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkvb7_.dbf

So we keep seeing multiple errors about files already existing - very odd. WHat stood out to me though was that the file names were now very long and something in my distant memory remembered that there were 128 character limits at some point on file names - i wonder...

SQL> select length('/oracle/ENDUR-ACFS/.ACFS/snaps/EC440910DBE32715E0430200007FDFBC/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkrm4_.dbf') from dual;

LENGTH('/ORACLE/ENDUR-ACFS/.ACFS/SNAPS/EC440910DBE32715E0430200007FDFBC/ENDCON/E
--------------------------------------------------------------------------------
                                                                             138

So they are longer than 128 - lets try renaming

[oracle@server]:ENDCON:[/oracle/ENDUR-ACFS/datafile]#  mv /oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/*.dbf .

alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_system_99gm7pxp_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_system_99gm7pxp_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_sysaux_99gm7pxp_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_sysaux_99gm7pxp_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkcfc_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkcfc_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkojs_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkojs_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkr1d_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkr1d_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkrm4_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkrm4_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkslm_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkslm_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmktho_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmktho_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkvb7_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkvb7_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkw3m_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkw3m_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkwv4_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkwv4_.dbf';
alter database rename file'/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_endur_99gmkxlo_.dbf' to '/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkxlo_.dbf';

SQL> alter pluggable database endur01 open read only;
Pluggable database altered.
SQL> set timing on
SQL> create pluggable database endur02 from endur01 snapshot copy;
create pluggable database endur02 from endur01 snapshot copy
ERROR at line 1:
ORA-65040: operation not allowed from within a pluggable database

Let's switch back to the container again.....
SQL> alter session set container=CDB$ROOT;
Session altered.
Elapsed: 00:00:00.01
SQL> create pluggable database endur02 from endur01 snapshot copy;
create pluggable database endur02 from endur01 snapshot copy
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level
ORA-17517: Database cloning using storage snapshot failed on file :
Elapsed: 00:00:00.37
SQL>

Come on this is getting ridicolous - lets check the trace again.

*** 2013-11-28 21:21:51.206
*** SESSION ID:(66.39) 2013-11-28 21:21:51.206
*** CLIENT ID:() 2013-11-28 21:21:51.206
*** SERVICE NAME:(SYS$USERS) 2013-11-28 21:21:51.206
*** MODULE NAME:(sqlplus@server (TNS V1-V3)) 2013-11-28 21:21:51.206
*** ACTION NAME:() 2013-11-28 21:21:51.206
*** CONTAINER ID:(1) 2013-11-28 21:21:51.206

failed to link target:/oracle/ENDUR-ACFS/ENDCON/EC444D5035396747E0430200007FBA56/datafile/o1_mf_endur_99hdzgyq_.dbf to clone:/oracle/ENDUR-

ACFS/.ACFS/snaps/EC444D5035396747E0430200007FBA56/datafile/o1_mf_endur_99gmkw3m_.dbf
ORA-17517: Database cloning using storage snapshot failed on file 6:/oracle/ENDUR-ACFS/datafile/o1_mf_endur_99gmkw3m_.dbf
ORA-27040: file create error, unable to create file
Linux-x86_64 Error: 17: File exists
Additional information: 101

It's still on about the old names let's restart everything, DB was fine - now ASM

SQL> shutdown;
ORA-15487: cannot shutdown the ASM instance with an open ASM volume
SQL> select group_number,name,state from v$asm_diskgroup;

GROUP_NUMBER NAME                           STATE
------------ ------------------------------ -----------
           2 ENDUR_DG                       MOUNTED
           1 DATA                           MOUNTED

SQL> shutdown immediate;
ORA-15487: cannot shutdown the ASM instance with an open ASM volume
SQL> alter diskgroup ENDUR_DG dismount;
alter diskgroup ENDUR_DG dismount
*
ERROR at line 1:
ORA-15032: not all alterations performed
ORA-15027: active use of diskgroup "ENDUR_DG" precludes its dismount


It doesn;t want to die, lets kill it.
SQL> shutdown abort;
ASM instance shutdown
SQL>
SQL>
SQL> startup
ASM instance started

Total System Global Area 1135747072 bytes
Fixed Size                  2297344 bytes
Variable Size            1108283904 bytes
ASM Cache                  25165824 bytes
ASM diskgroups mounted
ORA-15032: not all alterations performed
ORA-15489: conflicting volume already open on this node
ORA-15489: conflicting volume already open on this node

Oh dear killing was not a good idea

SQL> select group_number,name,state from v$asm_diskgroup;

GROUP_NUMBER NAME                           STATE
------------ ------------------------------ -----------
           2 ENDUR_DG                       MOUNTED
           1 DATA                           MOUNTED

SQL>

Lets see what state the volumes are in
ASMCMD> volinfo --all
Diskgroup Name: DATA

         Volume Name: TEST
         Volume Device: /dev/asm/test-393
         State: DISABLED
         Size (MB): 6144
         Resize Unit (MB): 32
         Redundancy: MIRROR
         Stripe Columns: 4
         Stripe Width (K): 128
         Usage: ACFS
         Mountpath: /oracle/ASCF

Diskgroup Name: ENDUR_DG

         Volume Name: ENDUR_VOL
         Volume Device: /dev/asm/endur_vol-273
         State: DISABLED
         Size (MB): 358400
         Resize Unit (MB): 32
         Redundancy: UNPROT
         Stripe Columns: 4
         Stripe Width (K): 128
         Usage: ACFS
         Mountpath: /oracle/ENDUR-ACFS


Lets try and enable them......

ASMCMD> volenable --all
ORA-15032: not all alterations performed
ORA-15489: conflicting volume already open on this node
ORA-15489: conflicting volume already open on this node (DBD ERROR: OCIStmtExecute)
ASMCMD>

nope.. how about disable and then enable....
ASMCMD> voldisable --all
ORA-15032: not all alterations performed
ORA-15468: volume 'ENDUR_VOL' in diskgroup 'ENDUR_DG' is currently being accessed
ORA-15468: volume 'TEST' in diskgroup 'DATA' is currently being accessed (DBD ERROR: OCIStmtExecute)
ASMCMD> exit
You have new mail in /var/mail/oracle
[oracle@server]:+ASM:[/oracle/ENDUR-ACFS/datafile]# lsof |grep ACFS
lsof       3610     oracle  cwd       DIR         252,139777        8192        65 /oracle/ENDUR-ACFS/datafile
grep       3611     oracle  cwd       DIR         252,139777        8192        65 /oracle/ENDUR-ACFS/datafile
lsof       3612     oracle  cwd       DIR         252,139777        8192        65 /oracle/ENDUR-ACFS/datafile
bash      17846     oracle  cwd       DIR         252,139777        8192        65 /oracle/ENDUR-ACFS/datafile

I'm sat in one of the directories maybe that's the problem. lets move.
[oracle@server]:+ASM:[/oracle/ENDUR-ACFS/datafile]#
[oracle@server]:+ASM:[/oracle/ENDUR-ACFS/datafile]# cd
[oracle@server]:+ASM:[~]# lsof |grep ACFS

Now nothign shows up in lsof
Lets try volenable again
[oracle@server]:+ASM:[~]# asmcmd
ASMCMD> volenable --all
ORA-15032: not all alterations performed
ORA-15489: conflicting volume already open on this node
ORA-15489: conflicting volume already open on this node (DBD ERROR: OCIStmtExecute)

How about a restart of crs

[oracle@server]:+ASM:[~]# crsctl stop has
CRS-2791: Starting shutdown of Oracle High Availability Services-managed resources on 'server'
CRS-2673: Attempting to stop 'ora.LISTENER.lsnr' on 'server'
CRS-2673: Attempting to stop 'ora.evmd' on 'server'
CRS-2677: Stop of 'ora.LISTENER.lsnr' on 'server' succeeded
CRS-2677: Stop of 'ora.evmd' on 'server' succeeded
CRS-2673: Attempting to stop 'ora.cssd' on 'server'
CRS-2677: Stop of 'ora.cssd' on 'server' succeeded
CRS-2793: Shutdown of Oracle High Availability Services-managed resources on 'server' has completed
CRS-4133: Oracle High Availability Services has been stopped.

[oracle@server]:+ASM:[~]# crsctl start has

CRS-4123: Oracle High Availability Services has been started.
You have new mail in /var/mail/oracle
Still no joy - time to reluctantly ask the unix team to unmount/mount (even though the are not mounted at the moment)
/bin/umount –t acfs /oracle/ENDUR-ACFS
/bin/umount –t acfs /oracle/ASCF
/bin/mount -t acfs /dev/asm/endur_vol-273 /oracle/ENDUR-ACFS
/bin/mount -t acfs /dev/asm/test-393 /oracle/ASCF

Now restart ASM
SQL*Plus: Release 12.1.0.1.0 Production on Fri Nov 29 10:38:16 2013

Copyright (c) 1982, 2013, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> startup
ORACLE instance started.

Total System Global Area 3.0398E+10 bytes
Fixed Size                  2699368 bytes
Variable Size            3288338328 bytes
Database Buffers         2.7045E+10 bytes
Redo Buffers               62296064 bytes
Database mounted.
Database opened.
SQL> sho pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED
---------- ------------------------------ ---------- ----------
         2 PDB$SEED                       READ ONLY  NO
         3 ENDUR01                        MOUNTED
SQL> alter pluggable database endur01 open read only;

Pluggable database altered.

SQL>

And it's fixed hoorah - seems the ACFS mount/unmount is held somewhere that only unmount os removing properly
Now lets try yet again

SQL>  create pluggable database endur02 from endur01 snapshot copy file_name_convert=('/oracle/ENDUR-ACFS/datafile/','/oracle/ENDUR-ACFS/ENDUR02');
 create pluggable database endur02 from endur01 snapshot copy file_name_convert=('/oracle/ENDUR-ACFS/datafile/','/oracle/ENDUR-ACFS/ENDUR02')
*
ERROR at line 1:
ORA-65005: missing or invalid file name pattern for file -
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_temp_9
9hdnkmw_.tmp

Aaargh - but progress at least - lets add a new tempfile and drop the old one
SQL> alter tablespace temp add tempfile '/oracle/ENDUR-ACFS/datafile/temp02.dbf' size 64M autoextend on;
Tablespace altered.

Hold on need to do that in the PDB...
SQL> alter tablespace temp drop tempfile '/oracle/ENDUR-ACFS/datafile/temp02.dbf';
Tablespace altered.
SQL> alter session set container=ENDUR01;
Session altered.
SQL> sho pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED
---------- ------------------------------ ---------- ----------
         3 ENDUR01                        READ ONLY  NO
SQL> select * from dba_temp_files;

FILE_NAME
--------------------------------------------------------------------------------
   FILE_ID TABLESPACE_NAME                     BYTES     BLOCKS STATUS
---------- ------------------------------ ---------- ---------- -------
RELATIVE_FNO AUT   MAXBYTES  MAXBLOCKS INCREMENT_BY USER_BYTES USER_BLOCKS
------------ --- ---------- ---------- ------------ ---------- -----------
/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_temp_9
9hdnkmw_.tmp
         3 TEMP                             20971520       2560 OFFLINE
           1 YES 3.4360E+10    4194302           80   19922944        2432


SQL> alter tablespace temp add tempfile '/oracle/ENDUR-ACFS/datafile/temp02.dbf' size 64M autoextend on;

Tablespace altered.

SQL> alter tablespace temp drop tempfile '/oracle/ENDUR-ACFS/ENDCON/EC3E26CC957C4E33E0430200007FE008/datafile/o1_mf_temp_99hdnkmw_.tmp';

Tablespace altered.

Right now it's going to work
SQL> set timing on
Create new directory for the clone.
SQL> !mkdir /oracle/ENDUR-ACFS/ENDUR02
And here we go
SQL> create pluggable database endur02 from endur01 snapshot copy file_name_convert=('/oracle/ENDUR-ACFS/datafile/','/oracle/ENDUR-ACFS/ENDUR02');
create pluggable database endur02 from endur01 snapshot copy file_name_convert=('/oracle/ENDUR-ACFS/datafile/','/oracle/ENDUR-ACFS/ENDUR02')
*
ERROR at line 1:
ORA-00059: maximum number of DB_FILES exceeded

WTF! - this can;t be - there are only about 20 files - lets check setting

db_files                             integer     200

That makes no sense - something has cached all these failed creations and has eaten up all the DB_FILES. Not sure how to fix as everything has been restarted - so all i can do is increase db files and restart. So it's not increased to 1000.

And..........
SQL> create pluggable database endur02 from endur01 snapshot copy file_name_convert=('/oracle/ENDUR-ACFS/datafile/','/oracle/ENDUR-ACFS/ENDUR02');

Pluggable database created.

Elapsed: 00:00:06.25

It's a miracle - it actually worked.
ANd now the best bit.
Time taken to clone 300GB = 6.25 seconds
Space taken for clone 200MB

So after a lot of suffering we have some very promising results - now to see how much the clone grows over time with activity - I'll report back when i have more info.
It looks like i found 2 bugs along the way though - maybe this blog helps someone who hits these issues.

Comments