Author Topic: HELP!! - "Mount error! Cannot create a file when that file already exists."  (Read 1794 times)

Offline ethanwa

  • Newbie
  • *
  • Posts: 17
  • Karma: +0/-0
    • View Profile
Here are my logs. Already tried uninstalling and reinstalling FlexRAID and recreating the pool five times. This happens when I create a new pool of 24 drives and try to start the pool:

[2012-08-30 18:37:51,689] INFO : Starting FlexRAID...
[2012-08-30 18:37:51,689] INFO : FlexRAID 2.0u9 final [Snapshot 1.4 stable / Storage Pool 1.0 RC / Real-Time 1.0 experimental]
[2012-08-30 18:37:51,689] INFO : Started: August 30, 2012 6:37:51 PM PDT
[2012-08-30 18:37:51,699] INFO : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
[2012-08-30 18:37:51,699] INFO : Quartz Scheduler v.1.8.4 created.
[2012-08-30 18:37:51,699] INFO : Registering Quartz shutdown hook.
[2012-08-30 18:37:51,699] INFO : Using thread monitor-based data access locking (synchronization).
[2012-08-30 18:37:51,704] INFO : Removed 0 Volatile Trigger(s).
[2012-08-30 18:37:51,704] INFO : Removed 0 Volatile Job(s).
[2012-08-30 18:37:51,704] INFO : JobStoreTX initialized.
[2012-08-30 18:37:51,704] INFO : Scheduler meta-data: Quartz Scheduler (v1.8.4) 'flexraid' with instanceId '1'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 3 threads.
  Using job-store 'org.quartz.impl.jdbcjobstore.JobStoreTX' - which supports persistence. and is not clustered.

[2012-08-30 18:37:51,704] INFO : Quartz scheduler 'flexraid' initialized from default resource file in Quartz package: 'quartz.properties'
[2012-08-30 18:37:51,704] INFO : Quartz scheduler version: 1.8.4
[2012-08-30 18:37:51,709] INFO : Freed 0 triggers from 'acquired' / 'blocked' state.
[2012-08-30 18:37:51,710] INFO : Recovering 0 jobs that were in-progress at the time of the last shut-down.
[2012-08-30 18:37:51,710] INFO : Recovery complete.
[2012-08-30 18:37:51,711] INFO : Removed 0 'complete' triggers.
[2012-08-30 18:37:51,711] INFO : Removed 0 stale fired job entries.
[2012-08-30 18:37:51,711] INFO : Scheduler flexraid_$_1 started.
[2012-08-30 18:37:51,713] INFO : jetty-7.x.y-SNAPSHOT
[2012-08-30 18:37:51,716] INFO : started o.e.j.s.ServletContextHandler{/,null}
[2012-08-30 18:37:51,716] TRACE: keepalive=true
[2012-08-30 18:37:51,716] TRACE: keepalive=true
[2012-08-30 18:37:51,718] TRACE: Executing: smart
[2012-08-30 18:37:51,718] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:54,170] INFO : Started SocketConnector@0.0.0.0:8080 STARTING
[2012-08-30 18:37:57,167] WARN : /gwt/rpc
java.lang.RuntimeException: Login exception: unauthenticated user!
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
[2012-08-30 18:37:58,265] TRACE: Executing: view
[2012-08-30 18:37:58,265] TRACE: View Manager - executing state
[2012-08-30 18:37:58,266] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": [{"installed": true, "rebootRequired": false, "published": true, "markedToStartAutomatically": false, "autoStartDelay": 0, "hasSharesToReconnect": false, "running": false, "starting": false, "stopping": false}]}
[2012-08-30 18:37:58,316] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,316] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,317] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,317] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,317] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,317] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,318] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,318] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,318] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,318] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,319] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,319] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,319] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,319] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,320] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,320] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,320] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,321] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,321] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,321] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,321] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,322] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,322] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,322] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,323] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,323] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,323] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,323] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,324] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,324] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,324] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,324] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,325] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,325] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,325] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,325] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,326] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,326] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,326] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,326] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,326] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,327] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:37:58,327] TRACE: Executing: cruise-control
[2012-08-30 18:37:58,327] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": []}
[2012-08-30 18:38:00,425] TRACE: Executing: view
[2012-08-30 18:38:00,425] TRACE: View Manager - executing state
[2012-08-30 18:38:00,426] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": [{"installed": true, "rebootRequired": false, "published": true, "markedToStartAutomatically": false, "autoStartDelay": 0, "hasSharesToReconnect": false, "running": false, "starting": false, "stopping": false}]}
[2012-08-30 18:38:00,460] TRACE: Executing: view
[2012-08-30 18:38:00,460] TRACE: View Manager - executing state
[2012-08-30 18:38:00,460] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": [{"installed": true, "rebootRequired": false, "published": true, "markedToStartAutomatically": false, "autoStartDelay": 0, "hasSharesToReconnect": false, "running": false, "starting": false, "stopping": false}]}
[2012-08-30 18:38:00,460] TRACE: Executing: view
[2012-08-30 18:38:00,461] TRACE:    => {"success": true, "status": null, "commandMessages": [{"messageCode": "successSuccessfulOperation", "messageData": []}], "serverMessages": null}
[2012-08-30 18:38:00,461] TRACE: Executing: view
[2012-08-30 18:38:00,461] TRACE: View Manager - executing state
[2012-08-30 18:38:00,462] TRACE:    => {"success": true, "status": null, "commandMessages": [], "serverMessages": null, "infos": [{"installed": true, "rebootRequired": false, "published": true, "markedToStartAutomatically": false, "autoStartDelay": 0, "hasSharesToReconnect": false, "running": false, "starting": false, "stopping": false}]}
[2012-08-30 18:38:00,462] TRACE: Executing: view
[2012-08-30 18:38:00,462] TRACE:    => {"success": true, "status": null, "commandMessages": [{"messageCode": "successSuccessfulOperation", "messageData": []}], "serverMessages": null}
[2012-08-30 18:38:00,462] TRACE: Executing: view
[2012-08-30 18:38:00,462] TRACE:    => {"success": true, "status": null, "commandMessages": [{"messageCode": "successSuccessfulOperation", "messageData": []}], "serverMessages": null}
[2012-08-30 18:38:00,462] TRACE: Executing: view
[2012-08-30 18:38:00,462] TRACE:    => {"success": true, "status": null, "commandMessages": [{"messageCode": "successSuccessfulOperation", "messageData": []}], "serverMessages": null}
[2012-08-30 18:38:01,488] TRACE: Executing: view
[2012-08-30 18:38:01,488] TRACE: View Manager - executing start
[2012-08-30 18:38:01,488] TRACE: Starting the Storage Pool - checking if instance is active...
[2012-08-30 18:38:01,488] TRACE: Starting the Storage Pool - checking if reboot is required...
[2012-08-30 18:38:01,488] TRACE: Starting the Storage Pool - validating dependencies...
[2012-08-30 18:38:01,489] INFO : Initiating FlexRAID Storage Pool...
[2012-08-30 18:38:01,517] INFO : Host OS = Microsoft Windows [Version 6.1.7601]
[2012-08-30 18:38:01,517] INFO : Building View Registry...
[2012-08-30 18:38:01,517] INFO : Building Auto View Registry...
[2012-08-30 18:38:01,520] INFO : Loading View options...
[2012-08-30 18:38:01,522] DEBUG: Processing match list...
[2012-08-30 18:38:01,522] DEBUG: Processing unique roots...
[2012-08-30 18:38:01,522] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{3ddb7399-789f-4c6e-954d-97bd416b245a}
[2012-08-30 18:38:01,522] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{8bd38d0f-750b-482b-bb02-59ef7e720820}
[2012-08-30 18:38:01,522] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{4dff2907-e4f1-11e1-b1d4-8c89a5de7ee1}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{4dff290c-e4f1-11e1-b1d4-8c89a5de7ee1}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{050ea1e6-0082-4b50-9383-452547a69833}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{38f2874a-820c-490a-bad4-96330abbcd66}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{672b9498-1363-4fa7-a3ab-fcd3ce029a9b}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{3266408e-1792-4a01-827e-91be828723f3}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{e7a8650d-1a52-47a5-9bef-c06c915a834f}
[2012-08-30 18:38:01,523] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{4dff2911-e4f1-11e1-b1d4-8c89a5de7ee1}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{0e1784d8-2b1f-4e11-9254-d596f4716a71}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{307be6b5-39d4-4912-af2e-b5093e9a2907}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{77a96fed-c423-4e47-b5e1-396e307a3df4}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{9fdb28c5-ccf8-4026-8888-953ae1e5ba97}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{c0b7fc65-8a92-4641-b283-c82367c43adf}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{8706218c-4c72-47f7-91e0-7fa9709a710f}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{8ad24bdd-b4dd-43a7-990d-9080198792b3}
[2012-08-30 18:38:01,524] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{347e8776-db44-49d4-9693-246207c2204c}
[2012-08-30 18:38:01,525] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{d6c73366-0d03-49bb-92ab-b662b4dbd279}
[2012-08-30 18:38:01,525] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{8d27c625-89a2-4bd0-b442-95ce26070064}
[2012-08-30 18:38:01,525] DEBUG: Processing unique root: C:\FlexRAID-Managed-Pool\class1_0\{40e4fac5-e145-43a4-87d6-fa179165c723}
[2012-08-30 18:38:01,525] TRACE: Loading AutoRegistry options...
[2012-08-30 18:38:01,525] TRACE: Completing AutoRegistry options...
[2012-08-30 18:38:01,531] TRACE: Loading View definition...
[2012-08-30 18:38:01,531] INFO : Using Auto-View definition...
[2012-08-30 18:38:01,531] INFO : Building View Handler...
[2012-08-30 18:38:01,588] INFO : Mounting Storage Pool drive...
[2012-08-30 18:38:07,091] WARN : Active Storage Pool initialization failure... aborting!
[2012-08-30 18:38:07,091] ERROR: Storage Pool handler initialization failure!
java.io.IOException: Storage Pool handler initialization failure!
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
   at java.lang.Void.<unknown>(Unknown Source)
[2012-08-30 18:38:07,091] TRACE: Checking and executing after pool start instructions..
[2012-08-30 18:38:07,091] TRACE:    => {"success": false, "status": null, "commandMessages": [{"messageCode": "errorExceptionMessage", "messageData": ["Storage Pool handler initialization failure!"]}], "serverMessages": null}


--------------- Storage Pool Start ---------------
[2012-8-31 1:38:1.590211][3520][Mounting Storage Pool]
[2012-8-31 1:38:1.590211][3520][VM already acquired...]
[2012-8-31 1:38:1.590211][3520][Setting handler...]
[2012-8-31 1:38:1.590211][3520][Initializing IDs...]
[2012-8-31 1:38:1.590211][3520][InitCommonIDs]
[2012-8-31 1:38:1.590212][3520][InitCommonIDs] Done
[2012-8-31 1:38:1.590212][3520][InitWinIDs]
[2012-8-31 1:38:1.590212][3520][InitWinIDs] Done
[2012-8-31 1:38:1.590212][3520][InitOSIDs]
[2012-8-31 1:38:1.590212][3520][InitOSIDs] Done
[2012-8-31 1:38:1.590212][3520][Reading live options...]
[2012-8-31 1:38:1.590212][3520][Reading user options...]
[2012-8-31 1:38:1.590212][3520][Building security...]
[2012-8-31 1:38:1.590212][3520][Building options...]
[2012-8-31 1:38:1.590212][3520][GUID: 842CF6CE-B3E2-4fd9-8efD-E28sL84FDS80]
[2012-8-31 1:38:1.592217][3520][OnMount]
[2012-8-31 1:38:1.592217][3520]      [OnMount] => Exited...
[2012-8-31 1:38:1.602248][3808][OnGetVolumeId]
[2012-8-31 1:38:1.602249][3808]      [OnGetVolumeId] => Exited...
[2012-8-31 1:38:1.602250][3520]Mount error! Code=183 Message=Cannot create a file when that file already exists.


[2012-8-31 1:38:1.611278][2120][OnUnmount]
[2012-8-31 1:38:1.611278][2120]      [OnUnmount] => Exited...
« Last Edit: August 30, 2012, 08:39:34 pm by ethanwa »

Offline balchy

  • Newbie
  • *
  • Posts: 31
  • Karma: +1/-0
    • View Profile
Here's a guess: in the storage pool configuration is the drive letter for the pool configured to a free and available drive letter?  Mine defaulted to "V:"
Also, I count only 21 unique root mounts ... not sure if that is significant
How are the drives mounted before you initialise Flexraid - are you using drive letters or mount points?

Offline Brahim

  • Global Moderator
  • Hero Member
  • *****
  • Posts: 8,547
  • Karma: +204/-16
    • View Profile
Here's a guess: in the storage pool configuration is the drive letter for the pool configured to a free and available drive letter?  Mine defaulted to "V:"
Also, I count only 21 unique root mounts ... not sure if that is significant
How are the drives mounted before you initialise Flexraid - are you using drive letters or mount points?
+1

@ethanwa
1. Make sure the drive letter for the pool is free
2. Try rebooting

Offline ethanwa

  • Newbie
  • *
  • Posts: 17
  • Karma: +0/-0
    • View Profile
Making sure one of my drives wasn't V: solved the problem. Thanks guys!