search

storj-archived / storjshare-gui

Development on pause
https://storj.io/share.html
GNU Affero General Public License v3.0
460 stars 100 forks source link

Drive gets stuck in "preparing" #418

Closed rsmmnt closed 7 years ago

rsmmnt commented 7 years ago

Versions

Replace the values below with your own:

GUI 2.0.12 both test and common versions on Windows 7

Expected Behavior

Please describe the program's expected behavior.

normal running states of all drives

Actual Behavior

Please describe the program's actual behavior. Please include any stack trace

One drive of 2 gets stuck in "preparing" after some time running and never recovers normal running state. NTP is being synced once in half an hour so it's not an issue. Last log info:

{info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] shutting down tunnel server {info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] shutting down gateway 2540bf129da33b7c7c1ac35184680612da8593b067cbd9f364842ca4e65b63c7 {info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] shutting down gateway c3415b0e441a67c0a7536602480c10579d7f95029428f4ed3658701b20f39230 {info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] tunnel gateway on port 36211 closed {info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] tunnel gateway on port 36210 closed {info} [Mon Oct 24 2016 22:34:10 GMT+0300 (Романское время (зима))] tunnel gateway on port 36211 closed {info} [Mon Oct 24 2016 22:34:11 GMT+0300 (Романское время (зима))] tunnel gateway on port 36210 closed {warn} [Mon Oct 24 2016 22:34:12 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:34:11 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:34:41 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:09 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:10 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:13 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:13 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:28 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:29 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:29 GMT+0300 (Романское время (зима))] missing or empty reply from contact {warn} [Mon Oct 24 2016 22:38:29 GMT+0300 (Романское время (зима))] missing or empty reply from contact

Steps to Reproduce

Please include the steps the reproduce the issue, numbered below. Include as much detail as possible.

run windows share GUI with many drives for some time.

Screenshots (Optional)

If the error is graphical in nature it is helpful to provide a screenshot.

rsmmnt commented 7 years ago

{info} Restarting farmer [8f5938] ... stuck state in dev tools

rsmmnt commented 7 years ago

{debug} [Tue Oct 25 2016 15:21:04 GMT+0300 (Романское время (зима))] cleaning bad contacts from routing table {debug} [Tue Oct 25 2016 15:21:04 GMT+0300 (Романское время (зима))] dropping 0 bad contacts from router {debug} [Tue Oct 25 2016 15:21:05 GMT+0300 (Романское время (зима))] checking pending rpc callbacks for expirations {warn} [Tue Oct 25 2016 15:21:16 GMT+0300 (Романское время (зима))] missing or empty reply from contact {debug} [Tue Oct 25 2016 15:21:20 GMT+0300 (Романское время (зима))] checking pending rpc callbacks for expirations {warn} [Tue Oct 25 2016 15:21:29 GMT+0300 (Романское время (зима))] missing or empty reply from contact {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] no storage item available for this shard {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] negotiator returned: true {debug} [Tue Oct 25 2016 15:21:32 GMT+0300 (Романское время (зима))] we have enough free space: true {warn} [Tue Oct 25 2016 15:21:34 GMT+0300 (Романское время (зима))] missing or empty reply from contact {debug} [Tue Oct 25 2016 15:21:35 GMT+0300 (Романское время (зима))] checking pending rpc callbacks for expirations

before stuck state in debugging mode

CCTrollz commented 7 years ago

Also get this issue. However, after enough restarting and reloading the client, it eventually work with all drives connected. However, neither drive sees traffic when this happens.

CJClaude commented 7 years ago

Also seeing this. A reload will prepare for a few minutes, connect for awhile, then slip back into preparing mode. Only a reload appears to temporarily cure it (I've left it for over 30 minutes without it coming back online)

Running 2.0.13 under Windows 7 on a quad core I7 with 16gb of memory.

hvanzyll commented 7 years ago

running windows server 2012 when running version 2.0.12, it was stuck on preparing for over 3 days... upgraded to version 2.0.13 and 2 1/2 hours later still stating preparing capture

hvanzyll commented 7 years ago

Other notes, Deleted my old drive share and folder on my machine and created a new drive share @ 5:30 Attached log file from start of the time of the new drive, so log should be around 2 1/2 hours. StorjDrive-9775f4_2016-10-26.zip

littleskunk commented 7 years ago

{warn} [Wed Oct 26 2016 17:31:45 GMT-0600 (Mountain Daylight Time)] System clock is not syncronized with NTP

CJClaude commented 7 years ago

@skunk's point being you need to sync your clock or nothing works!

ero79 commented 7 years ago

Versions

Also have had this problem since 2.0.11

now on 2.0.13 - completely uninstalled program, deleted files from install directory, from appdata/user/roaming directory, and from the drive's directory.

new install, setup as fresh, has Preparing...

windows 8.1 Pro - 32GB ram, 64-bit

NOTE - I see errors about the time not being sync'd so i sync'd with time.nist.gov instead of the default of time.windows.com which is timing out and still have the same problem - altho after 5 minutes, it did just start to running so perhaps that was the problem

Expected Behavior

Should start like it did prior to v 2.0.11

Actual Behavior

Single drive (on a USB drive, not a local hard drive) - gets stuck on Preparing...

[1477580933044] Log file created. {warn} [Thu Oct 27 2016 10:08:55 GMT-0500 (Central Daylight Time)] could not connect to NAT device via UPnP: 63497 {warn} [Thu Oct 27 2016 10:08:55 GMT-0500 (Central Daylight Time)] failed to map port for tunserver: timeout {warn} [Thu Oct 27 2016 10:08:55 GMT-0500 (Central Daylight Time)] could not connect to NAT device via UPnP: 3692 {info} [Thu Oct 27 2016 10:08:55 GMT-0500 (Central Daylight Time)] node created with nodeID 5f5e3fcf9a1c7ed0b18cc98b7dbcc85e78be7bf4 {warn} [Thu Oct 27 2016 10:08:55 GMT-0500 (Central Daylight Time)] System clock is not syncronized with NTP {info} [Thu Oct 27 2016 10:08:56 GMT-0500 (Central Daylight Time)] requesting probe from nearest neighbor {info} [Thu Oct 27 2016 10:08:56 GMT-0500 (Central Daylight Time)] sending PROBE message to {"userAgent":"4.1.0","protocol":"0.9.1","address":"91.237.220.80","port":33537,"nodeID":"05c6acd747db4cac9448dbb0512d47cf20ba5e38","lastSeen":1477580936273} {warn} [Thu Oct 27 2016 10:09:17 GMT-0500 (Central Daylight Time)] missing or empty reply from contact {warn} [Thu Oct 27 2016 10:09:23 GMT-0500 (Central Daylight Time)] rpc call 42364b99582976bc0af300906a5d97a037e51f3d timed out {info} [Thu Oct 27 2016 10:09:23 GMT-0500 (Central Daylight Time)] requesting tunnelers from neighbor {info} [Thu Oct 27 2016 10:09:23 GMT-0500 (Central Daylight Time)] sending FIND_TUNNEL message to {"userAgent":"4.1.0","protocol":"0.9.1","address":"91.237.220.80","port":33537,"nodeID":"05c6acd747db4cac9448dbb0512d47cf20ba5e38","lastSeen":1477580963564} {warn} [Thu Oct 27 2016 10:09:44 GMT-0500 (Central Daylight Time)] missing or empty reply from contact {warn} [Thu Oct 27 2016 10:09:53 GMT-0500 (Central Daylight Time)] rpc call 1d54ec2bbadb07c986d1a0aaace7e42862af07b4 timed out {info} [Thu Oct 27 2016 10:09:53 GMT-0500 (Central Daylight Time)] requesting tunnelers from neighbor {info} [Thu Oct 27 2016 10:09:53 GMT-0500 (Central Daylight Time)] sending FIND_TUNNEL message to {"userAgent":"4.1.0","protocol":"0.9.1","address":"78.68.77.92","port":2617,"nodeID":"468338828e1e255aa9f682854c186688ac710071","lastSeen":1477580993574} {warn} [Thu Oct 27 2016 10:11:54 GMT-0500 (Central Daylight Time)] missing or empty reply from contact {warn} [Thu Oct 27 2016 10:17:01 GMT-0500 (Central Daylight Time)] could not connect to NAT device via UPnP: 64412 {warn} [Thu Oct 27 2016 10:17:01 GMT-0500 (Central Daylight Time)] failed to map port for tunserver: timeout {warn} [Thu Oct 27 2016 10:17:01 GMT-0500 (Central Daylight Time)] could not connect to NAT device via UPnP: 6915 {info} [Thu Oct 27 2016 10:17:01 GMT-0500 (Central Daylight Time)] node created with nodeID 5f5e3fcf9a1c7ed0b18cc98b7dbcc85e78be7bf4 {warn} [Thu Oct 27 2016 10:17:01 GMT-0500 (Central Daylight Time)] System clock is not syncronized with NTP {info} [Thu Oct 27 2016 10:17:02 GMT-0500 (Central Daylight Time)] requesting probe from nearest neighbor {info} [Thu Oct 27 2016 10:17:02 GMT-0500 (Central Daylight Time)] sending PROBE message to {"userAgent":"4.1.0","protocol":"0.9.1","address":"194.165.230.30","port":7060,"nodeID":"8a4f6234fa213ea88fa6f75c4ef7f0acd99670c7","lastSeen":1477581422252} {warn} [Thu Oct 27 2016 10:17:29 GMT-0500 (Central Daylight Time)] rpc call f10bb7c1bb8c9aedccbb27280b45a56b433ac8c9 timed out {info} [Thu Oct 27 2016 10:17:29 GMT-0500 (Central Daylight Time)] requesting tunnelers from neighbor {info} [Thu Oct 27 2016 10:17:29 GMT-0500 (Central Daylight Time)] sending FIND_TUNNEL message to {"userAgent":"4.1.0","protocol":"0.9.1","address":"194.165.230.30","port":7060,"nodeID":"8a4f6234fa213ea88fa6f75c4ef7f0acd99670c7","lastSeen":1477581449188}

Steps to Reproduce

Just starting the program, setting up a drive, and clicking Start

CCTrollz commented 7 years ago

It seems the latest update. .13 I think. Fixed this issue. Occasionally one of the drives is slow to come online however within 10 or so minutes all drive are connected and seem to stay connected.

On Wed, Oct 26, 2016, 10:24 PM hvanzyll notifications@github.com wrote:

Other notes, Deleted my old drive share and folder on my mmachine and created a new drive share @ 5:30 Attached log file from start of the time of the new drive, so log should be around 2 1/2 hours. StorjDrive-9775f4_2016-10-26.zip https://github.com/Storj/storjshare-gui/files/554835/StorjDrive-9775f4_2016-10-26.zip

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/Storj/storjshare-gui/issues/418#issuecomment-256529760, or mute the thread https://github.com/notifications/unsubscribe-auth/AJrWiOy8Qr74_jYSgkLZElqUkUrD6BKaks5q4AtugaJpZM4Kfutr .

hvanzyll commented 7 years ago

@ero79, looks like you have the same problem i have, System clock is not syncronized with NTP

my system is now counting shards... how long that will take duno

ero79 commented 7 years ago

interesting enough - after 35 minutes of running, it just went back to "preparing..." with no intervention on my part. (i removed the address info from the screenshot)

image

hvanzyll commented 7 years ago

After updating my clock, and restarting the app... it got stuck on Preparing... log file had nothing useful in it other then [1477579245532] Log file created.

once i closed the app and restarted it. the app work fine and appear to have connections and contract count is now 1.

perhaps adding some UI notification that the clock is not correct...

Thanks.