Author Topic: Stuck at 75% on Create  (Read 2187 times)

Offline shaefurr

  • Newbie
  • *
  • Posts: 13
  • Karma: +0/-0
    • View Profile
Stuck at 75% on Create
« on: October 12, 2011, 11:27:02 am »
So I have 3 DRUs and 1 PPU, all are WD green drives (Western Digital Caviar Green WD30EZRX 3TB), Theyre running off the SATA on my MSI H55m-E33 board. The memory is G.SKILL Ripjaws Series 8GB (2 x 4GB) 240-Pin DDR3 SDRAM DDR3 1333 (PC3 10666) Desktop Memory Model F3-10666CL9D-8GBRL. I've tried turning on Retry Read Error but keep getting the same error at 75% while Creating the parity data. I'm just completely stuck and don't know where to go from here, any ideas?


[2011-10-11 21:55:25,673] INFO : Executing create...
[2011-10-11 21:55:25,673] INFO : [create] started at: Tue Oct 11 21:55:25 MDT 2011
[2011-10-11 21:55:25,673] INFO : Using RAID engine Tx
[2011-10-11 21:55:28,371] INFO : *** Starting workers... ***
[2011-10-12 02:43:16,890] ERROR: Invalid state - Unexpected EOF!
java.io.IOException: Invalid state - Unexpected EOF!
   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)
[2011-10-12 02:43:16,905] ERROR: Invalid state - reading=false removing=false writing=false needsWriting=false computing=false needsComputing=true
java.io.IOException: Invalid state - reading=false removing=false writing=false needsWriting=false computing=false needsComputing=true
   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)
[2011-10-12 02:43:16,968] WARN : Operation is being aborted... re-validating last processed entries...
[2011-10-12 02:43:18,481] INFO : [create] completed at: Wed Oct 12 02:43:18 MDT 2011

Offline xliv

  • Global Moderator
  • Full Member
  • *****
  • Posts: 208
  • Karma: +7/-1
    • View Profile
Re: Stuck at 75% on Create
« Reply #1 on: October 12, 2011, 12:04:01 pm »
You need to enable debug, and see where it stucks.
You can have a corrupted source file, or even corrupted sectors on the source disk.

If debug does not show anything, maybe a scan disk with sector check would help.
Server HW: ASUS P8B-E/4L + PIKE 2008 SAS | Xeon E3-1230 | 8GB DDR3 ECC 1333 [Kingston - KVR1333D3E9SK2/8G] | Intel 320 - 80 Go (OS)
Server OS: Win7 64b EN
FlexRAID 2.0 latest build, Cruise Control, 7 DRUs (6x3TB,1x2TB), 1 PPU (2x2TB)

Offline someone

  • Jr. Member
  • **
  • Posts: 81
  • Karma: +0/-0
    • View Profile
Re: Stuck at 75% on Create
« Reply #2 on: October 12, 2011, 12:20:24 pm »
I agree w/ above, but since  it stuck at  exactly  same  percentage, I would suspect there is a file it have a problem reading with.  Since FR use the OS to read the data, I would think you may even need some other utility to fix this if that's the case.

Offline shaefurr

  • Newbie
  • *
  • Posts: 13
  • Karma: +0/-0
    • View Profile
Re: Stuck at 75% on Create
« Reply #3 on: October 12, 2011, 01:11:40 pm »
dumb question probably, but where is the setting to enable debug? and i've already ran chkdsk on all 3 of my DRU's and no problems were found.

Offline shaefurr

  • Newbie
  • *
  • Posts: 13
  • Karma: +0/-0
    • View Profile
Re: Stuck at 75% on Create
« Reply #4 on: October 12, 2011, 01:28:02 pm »
Nevermind I got debugging turned on and i'm trying to resume the create now.

Offline shaefurr

  • Newbie
  • *
  • Posts: 13
  • Karma: +0/-0
    • View Profile
Re: Stuck at 75% on Create
« Reply #5 on: October 12, 2011, 11:17:51 pm »
So i'm still having the same issues and starting to wonder if its a write error to the PPU?

[2011-10-12 22:12:26,322] INFO : [update] started at: Wed Oct 12 22:12:26 MDT 2011
[2011-10-12 22:12:26,415] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:26,540] INFO : Using RAID engine T1+
[2011-10-12 22:12:26,540] DEBUG: Exclusion match - Skipping N:\$RECYCLE.BIN...
[2011-10-12 22:12:26,540] DEBUG: Exclusion match - Skipping M:\$RECYCLE.BIN...
[2011-10-12 22:12:26,540] DEBUG: Exclusion match - Skipping O:\$RECYCLE.BIN...
[2011-10-12 22:12:26,790] DEBUG: Exclusion match - Skipping O:\System Volume Information...
[2011-10-12 22:12:26,821] DEBUG: Exclusion match - Skipping N:\System Volume Information...
[2011-10-12 22:12:26,977] DEBUG: Exclusion match - Skipping M:\System Volume Information...
[2011-10-12 22:12:28,771] INFO : Total process size = 359627118300
[2011-10-12 22:12:28,771] DEBUG: Re-sizing K:\001013.flxr
[2011-10-12 22:12:29,738] DEBUG: Processing M:\Movies\Inception (2010) Blu-Ray\Inception (2010) Blu-Ray.mkv
[2011-10-12 22:12:29,738] DEBUG: Processing N:\Movies\Armageddon (1998) Blu-Ray\Armageddon (1998) Blu-Ray.mkv
[2011-10-12 22:12:29,738] DEBUG: Processing O:\Movies\Transformers Set\Transformers Dark of the Moon (2011) Blu-Ray\Transformers Dark of the Moon (2011) Blu-Ray.mkv
[2011-10-12 22:12:29,738] DEBUG: Processing K:\000001.flxr
[2011-10-12 22:12:29,738] DEBUG: Processing range: start=1087210504314 stop=1446837622614 size=359627118300
[2011-10-12 22:12:29,738] DEBUG: Processing N:\Movies\The Good Guy (2009)\VIDEO_TS\VTS_01_3.VOB
[2011-10-12 22:12:29,738] DEBUG: Processing O:\Shows\The Pretender\Season 3\The Pretender - s03e14 - At the Hour of Our Death.avi
[2011-10-12 22:12:29,738] DEBUG: Processing K:\001013.flxr
[2011-10-12 22:12:29,738] DEBUG: Processing M:\Movies\True Lies (1994)\VIDEO_TS\VTS_01_3.VOB
[2011-10-12 22:12:30,004] DEBUG: Processing O:\Shows\The Pretender\Season 2\The Pretender - s02e08 - Hazards.avi
[2011-10-12 22:12:30,752] DEBUG: Processing K:\001014.flxr
[2011-10-12 22:12:30,784] DEBUG: Processing O:\Shows\Wildfire\Season 3\Wildfire - s03e03 - Moving On.avi
[2011-10-12 22:12:30,924] DEBUG: Processing N:\Movies\The Goonies (1985)\VIDEO_TS\VTS_01_1.VOB
[2011-10-12 22:12:31,939] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:31,939] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:31,939] DEBUG: session=null
[2011-10-12 22:12:31,939] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:31,939] DEBUG: servlet holder=
[2011-10-12 22:12:31,939] DEBUG: chain=
[2011-10-12 22:12:31,939] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:37,446] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:37,446] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:37,446] DEBUG: session=null
[2011-10-12 22:12:37,446] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:37,446] DEBUG: servlet holder=
[2011-10-12 22:12:37,446] DEBUG: chain=
[2011-10-12 22:12:37,446] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:42,953] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:42,953] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:42,953] DEBUG: session=null
[2011-10-12 22:12:42,953] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:42,953] DEBUG: servlet holder=
[2011-10-12 22:12:42,953] DEBUG: chain=
[2011-10-12 22:12:42,953] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:48,459] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:48,459] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:48,459] DEBUG: session=null
[2011-10-12 22:12:48,459] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:48,459] DEBUG: servlet holder=
[2011-10-12 22:12:48,459] DEBUG: chain=
[2011-10-12 22:12:48,459] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:53,966] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:53,966] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:53,966] DEBUG: session=null
[2011-10-12 22:12:53,966] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:53,966] DEBUG: servlet holder=
[2011-10-12 22:12:53,966] DEBUG: chain=
[2011-10-12 22:12:53,966] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:12:59,473] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:12:59,473] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:12:59,473] DEBUG: session=null
[2011-10-12 22:12:59,473] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:12:59,473] DEBUG: servlet holder=
[2011-10-12 22:12:59,473] DEBUG: chain=
[2011-10-12 22:12:59,473] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:04,980] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:04,980] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:04,980] DEBUG: session=null
[2011-10-12 22:13:04,980] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:04,980] DEBUG: servlet holder=
[2011-10-12 22:13:04,980] DEBUG: chain=
[2011-10-12 22:13:04,980] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:06,680] DEBUG: MisfireHandler: scanning for misfires...
[2011-10-12 22:13:06,680] DEBUG: Found 0 triggers that missed their scheduled fire-time.
[2011-10-12 22:13:10,487] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:10,487] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:10,487] DEBUG: session=null
[2011-10-12 22:13:10,487] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:10,487] DEBUG: servlet holder=
[2011-10-12 22:13:10,487] DEBUG: chain=
[2011-10-12 22:13:10,487] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:15,993] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:15,993] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:15,993] DEBUG: session=null
[2011-10-12 22:13:15,993] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:15,993] DEBUG: servlet holder=
[2011-10-12 22:13:15,993] DEBUG: chain=
[2011-10-12 22:13:15,993] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:21,501] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:21,501] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:21,501] DEBUG: session=null
[2011-10-12 22:13:21,501] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:21,501] DEBUG: servlet holder=
[2011-10-12 22:13:21,501] DEBUG: chain=
[2011-10-12 22:13:21,501] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:27,008] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:27,008] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:27,008] DEBUG: session=null
[2011-10-12 22:13:27,008] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:27,008] DEBUG: servlet holder=
[2011-10-12 22:13:27,008] DEBUG: chain=
[2011-10-12 22:13:27,008] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:32,515] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:32,515] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:32,515] DEBUG: session=null
[2011-10-12 22:13:32,515] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:32,515] DEBUG: servlet holder=
[2011-10-12 22:13:32,515] DEBUG: chain=
[2011-10-12 22:13:32,515] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:38,022] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:38,022] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:38,022] DEBUG: session=null
[2011-10-12 22:13:38,022] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:38,770] DEBUG: servlet holder=
[2011-10-12 22:13:38,770] DEBUG: chain=
[2011-10-12 22:13:38,770] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:41,594] ERROR: Invalid state - Unexpected EOF!
java.io.IOException: Invalid state - Unexpected EOF!
   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)
[2011-10-12 22:13:41,594] ERROR: Invalid state - reading=false removing=false writing=false needsWriting=false computing=false needsComputing=true
java.io.IOException: Invalid state - reading=false removing=false writing=false needsWriting=false computing=false needsComputing=true
   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)
[2011-10-12 22:13:41,594] ERROR: [update] error: Previous progress not ended!
java.lang.IllegalStateException: Previous progress not ended!
   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)
[2011-10-12 22:13:41,594] INFO : [update] completed at: Wed Oct 12 22:13:41 MDT 2011
[2011-10-12 22:13:43,528] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:43,528] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:43,528] DEBUG: session=null
[2011-10-12 22:13:43,528] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:43,528] DEBUG: servlet holder=
[2011-10-12 22:13:43,528] DEBUG: chain=
[2011-10-12 22:13:43,528] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:13:49,035] DEBUG: REQUEST /gwt/rpc on org.eclipse.jetty.server.HttpConnection@4919138
[2011-10-12 22:13:49,035] DEBUG: sessionManager=org.eclipse.jetty.server.session.HashSessionManager@49696d8
[2011-10-12 22:13:49,035] DEBUG: session=null
[2011-10-12 22:13:49,035] DEBUG: servlet=com.tchegbe.flexraid.main.a.c-77726648
[2011-10-12 22:13:49,035] DEBUG: servlet holder=
[2011-10-12 22:13:49,035] DEBUG: chain=
[2011-10-12 22:13:49,035] DEBUG: RESPONSE /gwt/rpc  200
[2011-10-12 22:14:06,694] DEBUG: MisfireHandler: scanning for misfires...
[2011-10-12 22:14:06,694] DEBUG: Found 0 triggers that missed their scheduled fire-time.

Offline shaefurr

  • Newbie
  • *
  • Posts: 13
  • Karma: +0/-0
    • View Profile
Re: Stuck at 75% on Create
« Reply #6 on: October 12, 2011, 11:46:21 pm »
So now its resumed the create and seems to be ok again, friggin Goonies VTS file was corrupt. It

[2011-10-12 22:12:30,924] DEBUG: Processing N:\Movies\The Goonies (1985)\VIDEO_TS\VTS_01_1.VOB

Thanks for all the help guys, hopefully it will complete this time.