Bug #13513: [keep-balance] hang on ComputeChangeSets - Arvados

Actions

Copy link

Bug #13513

closed

[keep-balance] hang on ComputeChangeSets

Added by Ward Vandewege almost 6 years ago. Updated over 5 years ago.

Status:

Resolved

Priority:

Normal

Assigned To:

Tom Clegg

Category:

Target version:

2018-06-06 Sprint

Story points:

Release:

Arvados 1.2

Release relationship:

Auto

Description

After the merge of 9918-index-timeouts, I'm observing that keep-balance hangs (?) on ComputeChangeSets:

May 22 14:06:37 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:06:37 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): done
May 22 14:08:40 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:08:40 zzzzz-ivpuk-v2udip63fnkdyxf (s3:///dhhck-keep-0) on dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): add 1043919 replicas to map
May 22 14:08:40 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:08:40 zzzzz-ivpuk-v2udip63fnkdyxf (s3:///dhhck-keep-0) on dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): done
May 22 14:08:40 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:08:40 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): done
May 22 14:08:40 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:08:40 GetCurrentState: took 10m6.992266703s
May 22 14:08:40 dhhck.arvadosapi.com keep-balance[11166]: 2018/05/22 14:08:40 ComputeChangeSets: start

I stopped it after ~42 minutes.

May 22 14:50:02 dhhck.arvadosapi.com systemd[1]: Stopping Arvados Keep Balance...
May 22 14:50:02 dhhck.arvadosapi.com systemd[1]: Stopped Arvados Keep Balance.

Command line:

/usr/bin/keep-balance -commit-trash

I also tried with -commit-pull enabled, and the behavior was unchanged.

Config file:

# cat /etc/arvados/keep-balance/keep-balance.yml 
###################################################################
#  THIS FILE IS MANAGED BY PUPPET -- CHANGES WILL BE OVERWRITTEN  #
###################################################################
Client:
    APIHost: dhhck.arvadosapi.com:443
    AuthToken: STRIPPED
    Insecure: false
KeepServiceTypes:
    - s3
RunPeriod: 14400s
CollectionBatchSize: 100000
CollectionBuffers: 1000

Bisecting:

0.1.20180322172032.41e612b59-1	(with extra patch to increase timeout to 20 minutes)	OK
1.1.4.20180403215323-1	(with extra patch to increase timeout to 20 minutes)	OK
1.1.4.20180420195921-1	(with extra patch to increase timeout to 20 minutes)	OK
1.1.4.20180426154228-1	(with extra patch to increase timeout to 20 minutes)	OK
1.1.4.20180426193406-1	(with extra patch to increase timeout to 20 minutes)	HANGS
1.1.4.20180510200716-1	(with extra patch to increase timeout to 20 minutes)	HANGS
1.1.4.20180518195015-1		HANGS

So, it looks like the problem was introduced between version 1.1.4.20180426154228-1 (fcfbbddf572db32008fcdc7d0750a13b8d6f3b1c) and version 1.1.4.20180426193406-1 (932e3d6e9a899cc662ea3934b79057d39cd88fed).

Subtasks 1 (0 open — 1 closed)

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Description updated (diff)

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Description updated (diff)

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Description updated (diff)

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Description updated (diff)

Actions

Copy link

Updated by Tom Morris almost 6 years ago

Target version set to 2018-06-06 Sprint

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Project changed from 35 to Arvados

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Subject changed from keep-balance hangs on ComputeChangeSets to [keep-balance] hang on ComputeChangeSets

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Assigned To set to Brad Chapman

Actions

Copy link

Updated by Ward Vandewege almost 6 years ago

Assigned To changed from Brad Chapman to Tom Clegg

Actions

Copy link

#10

Updated by Tom Clegg almost 6 years ago

Indeed, 1.1.4.20180426193406-1 was 932e3d6e9a899cc662ea3934b79057d39cd88fed, which merged #12708, including this:

    close(todo)
    go func() {
        wg.Wait()
        close(results)
    }()
    bal.collectStatistics(results)

close(todo) waits for workers to read everything from todo, but every worker waits forever for bal.collectStatistics() to receive its first result.

Should use the pattern "sending goroutine closes channel": run Apply() in a goroutine which closes todo when finished, and run the nWorkers loop in a goroutine which closes results after wg.Wait(). Then collectStatistics() can be called synchronously and nobody outside the nWorkers loop needs to know about the wg.

Actions

Copy link

#11

Updated by Tom Clegg almost 6 years ago

13513-balance-deadlock @ f1cf835d576de364faa7e94f5ba8caca5ad7be43

Actions

Copy link

#12

Updated by Ward Vandewege almost 6 years ago

Tom Clegg wrote:

13513-balance-deadlock @ f1cf835d576de364faa7e94f5ba8caca5ad7be43

Test run of this code:

May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 keep-balance dev started
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 starting up: will scan every 4h0m0s and on SIGUSR1
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 Run: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 skipping dhhck-bi6l4-blb6dtx0sx07d7k with service type "proxy" 
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 clearing existing trash lists, in case the new rendezvous order differs from previous run
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): send trash list: took 830.003µs
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): send trash list: took 909.802µs
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): send trash list: took 1.686482ms
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): send trash list: took 1.735439ms
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 GetCurrentState: start
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): retrieve indexes
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): retrieve indexes
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 zzzzz-ivpuk-aj576e1t62use9i (s3:///dhhck-keep-2) on dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): retrieve index
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 zzzzz-ivpuk-mkmes11v77mlcso (s3:///dhhck-keep-3) on dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): retrieve index
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): retrieve indexes
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 zzzzz-ivpuk-aexopqahib74kpp (s3:///dhhck-keep-1) on dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): retrieve index
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): retrieve indexes
May 29 19:34:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:16 zzzzz-ivpuk-v2udip63fnkdyxf (s3:///dhhck-keep-0) on dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): retrieve index
May 29 19:34:17 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:17 collections: 0/137062
May 29 19:34:19 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:19 collections: 1000/137062
May 29 19:34:20 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:20 collections: 2000/137062
May 29 19:34:21 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:21 collections: 3000/137062
May 29 19:34:22 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:22 collections: 4000/137062
May 29 19:34:23 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:23 collections: 5000/137062
May 29 19:34:24 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:24 collections: 6000/137062
May 29 19:34:25 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:25 collections: 7000/137062
May 29 19:34:25 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:25 collections: 8000/137062
May 29 19:34:26 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:26 collections: 9000/137062
May 29 19:34:27 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:27 collections: 10000/137062
May 29 19:34:28 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:28 collections: 11000/137062
May 29 19:34:29 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:29 collections: 12000/137062
May 29 19:34:29 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:29 collections: 13000/137062
May 29 19:34:30 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:30 collections: 14000/137062
May 29 19:34:31 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:31 collections: 15000/137062
May 29 19:34:32 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:32 collections: 16000/137062
May 29 19:34:33 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:33 collections: 17000/137062
May 29 19:34:34 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:34 collections: 18000/137062
May 29 19:34:34 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:34 collections: 19000/137062
May 29 19:34:36 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:36 collections: 20000/137062
May 29 19:34:39 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:39 collections: 21000/137062
May 29 19:34:42 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:42 collections: 22000/137062
May 29 19:34:43 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:43 collections: 23000/137062
May 29 19:34:44 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:44 collections: 24000/137062
May 29 19:34:44 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:44 collections: 25000/137062
May 29 19:34:45 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:45 collections: 26000/137062
May 29 19:34:46 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:46 collections: 27000/137062
May 29 19:34:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:47 collections: 28000/137062
May 29 19:34:48 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:48 collections: 29000/137062
May 29 19:34:49 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:49 collections: 30000/137062
May 29 19:34:50 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:50 collections: 31000/137062
May 29 19:34:51 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:51 collections: 32000/137062
May 29 19:34:52 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:52 collections: 33000/137062
May 29 19:34:53 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:53 collections: 34000/137062
May 29 19:34:54 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:54 collections: 35000/137062
May 29 19:34:55 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:55 collections: 36000/137062
May 29 19:34:56 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:56 collections: 37000/137062
May 29 19:34:57 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:57 collections: 38000/137062
May 29 19:34:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:58 collections: 39000/137062
May 29 19:34:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:34:59 collections: 40000/137062
May 29 19:35:00 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:00 collections: 41000/137062
May 29 19:35:01 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:01 collections: 42000/137062
May 29 19:35:02 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:02 collections: 43000/137062
May 29 19:35:03 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:03 collections: 44000/137062
May 29 19:35:04 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:04 collections: 45000/137062
May 29 19:35:05 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:05 collections: 46000/137062
May 29 19:35:06 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:06 collections: 47000/137062
May 29 19:35:07 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:07 collections: 48000/137062
May 29 19:35:08 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:08 collections: 49000/137062
May 29 19:35:09 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:09 collections: 50000/137062
May 29 19:35:10 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:10 collections: 51000/137062
May 29 19:35:11 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:11 collections: 52000/137062
May 29 19:35:12 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:12 collections: 53000/137062
May 29 19:35:13 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:13 collections: 54000/137062
May 29 19:35:14 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:14 collections: 55000/137062
May 29 19:35:15 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:15 collections: 56000/137062
May 29 19:35:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:16 collections: 57000/137062
May 29 19:35:17 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:17 collections: 58000/137062
May 29 19:35:18 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:18 collections: 59000/137062
May 29 19:35:19 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:19 collections: 60000/137062
May 29 19:35:20 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:20 collections: 61000/137062
May 29 19:35:21 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:21 collections: 62000/137062
May 29 19:35:22 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:22 collections: 63000/137062
May 29 19:35:23 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:23 collections: 64000/137062
May 29 19:35:24 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:24 collections: 65000/137062
May 29 19:35:25 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:25 collections: 66000/137062
May 29 19:35:26 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:26 collections: 67000/137062
May 29 19:35:27 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:27 collections: 68000/137062
May 29 19:35:28 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:28 collections: 69000/137062
May 29 19:35:29 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:29 collections: 70000/137062
May 29 19:35:30 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:30 collections: 71000/137062
May 29 19:35:31 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:31 collections: 72000/137062
May 29 19:35:32 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:32 collections: 73000/137062
May 29 19:35:33 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:33 collections: 74000/137062
May 29 19:35:34 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:34 collections: 75000/137062
May 29 19:35:35 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:35 collections: 76000/137062
May 29 19:35:36 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:36 collections: 77000/137062
May 29 19:35:37 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:37 collections: 78000/137062
May 29 19:35:38 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:38 collections: 79000/137062
May 29 19:35:39 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:39 collections: 80000/137062
May 29 19:35:40 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:40 collections: 81000/137062
May 29 19:35:41 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:41 collections: 82000/137062
May 29 19:35:41 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:41 collections: 83000/137062
May 29 19:35:42 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:42 collections: 84000/137062
May 29 19:35:43 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:43 collections: 85000/137062
May 29 19:35:44 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:44 collections: 86000/137062
May 29 19:35:45 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:45 collections: 87000/137062
May 29 19:35:46 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:46 collections: 88000/137062
May 29 19:35:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:47 collections: 89000/137062
May 29 19:35:48 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:48 collections: 90000/137062
May 29 19:35:49 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:49 collections: 91000/137062
May 29 19:35:50 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:50 collections: 92000/137062
May 29 19:35:51 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:51 collections: 93000/137062
May 29 19:35:52 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:52 collections: 94000/137062
May 29 19:35:52 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:52 collections: 95000/137062
May 29 19:35:53 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:53 collections: 96000/137062
May 29 19:35:54 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:54 collections: 97000/137062
May 29 19:35:55 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:55 collections: 98000/137062
May 29 19:35:55 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:55 collections: 99000/137062
May 29 19:35:56 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:56 collections: 100000/137062
May 29 19:35:57 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:57 collections: 101000/137062
May 29 19:35:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:58 collections: 102000/137062
May 29 19:35:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:58 collections: 103000/137062
May 29 19:35:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:35:59 collections: 104000/137062
May 29 19:36:00 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:00 collections: 105000/137062
May 29 19:36:01 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:01 collections: 106000/137062
May 29 19:36:01 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:01 collections: 107000/137062
May 29 19:36:02 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:02 collections: 108000/137062
May 29 19:36:03 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:03 collections: 109000/137062
May 29 19:36:04 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:04 collections: 110000/137062
May 29 19:36:04 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:04 collections: 111000/137062
May 29 19:36:05 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:05 collections: 112000/137062
May 29 19:36:06 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:06 collections: 113000/137062
May 29 19:36:07 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:07 collections: 114000/137062
May 29 19:36:07 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:07 collections: 115000/137062
May 29 19:36:08 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:08 collections: 116000/137062
May 29 19:36:09 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:09 collections: 117000/137062
May 29 19:36:10 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:10 collections: 118000/137062
May 29 19:36:10 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:10 collections: 119000/137062
May 29 19:36:11 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:11 collections: 120000/137062
May 29 19:36:12 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:12 collections: 121000/137062
May 29 19:36:13 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:13 collections: 122000/137062
May 29 19:36:13 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:13 collections: 123000/137062
May 29 19:36:14 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:14 collections: 124000/137062
May 29 19:36:15 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:15 collections: 125000/137062
May 29 19:36:15 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:15 collections: 126000/137062
May 29 19:36:16 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:16 collections: 127000/137062
May 29 19:36:17 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:17 collections: 128000/137062
May 29 19:36:18 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:18 collections: 129000/137062
May 29 19:36:19 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:19 collections: 130000/137062
May 29 19:36:19 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:19 collections: 131000/137062
May 29 19:36:20 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:20 collections: 132000/137062
May 29 19:36:21 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:21 collections: 133000/137062
May 29 19:36:22 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:22 collections: 134000/137062
May 29 19:36:22 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:22 collections: 135000/137062
May 29 19:36:24 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:24 collections: 136000/137062
May 29 19:36:26 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:26 collections: 137000/137062
May 29 19:36:27 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:27 collections: 137062/137062
May 29 19:36:27 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:36:27 collections: 137062/137062
May 29 19:40:03 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:40:03 zzzzz-ivpuk-aexopqahib74kpp (s3:///dhhck-keep-1) on dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): add 512782 replicas to map
May 29 19:40:03 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:40:03 zzzzz-ivpuk-aexopqahib74kpp (s3:///dhhck-keep-1) on dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): done
May 29 19:40:03 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:40:03 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): done
May 29 19:42:32 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:32 zzzzz-ivpuk-mkmes11v77mlcso (s3:///dhhck-keep-3) on dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): add 902720 replicas to map
May 29 19:42:33 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:33 zzzzz-ivpuk-mkmes11v77mlcso (s3:///dhhck-keep-3) on dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): done
May 29 19:42:33 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:33 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): done
May 29 19:42:42 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:42 zzzzz-ivpuk-aj576e1t62use9i (s3:///dhhck-keep-2) on dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): add 898276 replicas to map
May 29 19:42:43 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:43 zzzzz-ivpuk-aj576e1t62use9i (s3:///dhhck-keep-2) on dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): done
May 29 19:42:43 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:42:43 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): done

May 29 19:47:46 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:46 zzzzz-ivpuk-v2udip63fnkdyxf (s3:///dhhck-keep-0) on dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): add 1043916 replicas to map
May 29 19:47:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:47 zzzzz-ivpuk-v2udip63fnkdyxf (s3:///dhhck-keep-0) on dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): done
May 29 19:47:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:47 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): done
May 29 19:47:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:47 GetCurrentState: took 13m30.401416854s
May 29 19:47:47 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:47 ComputeChangeSets: start
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ComputeChangeSets: took 10.955702441s
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 0 replicas (0 blocks, 0 bytes) lost (0=have<want)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 0 replicas (0 blocks, 0 bytes) underreplicated (0<have<want)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 3357390 replicas (3357390 blocks, 199210561559859 bytes) just right (have=want)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 154 replicas (150 blocks, 1017715394 bytes) overreplicated (have>want>0)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 0 replicas (0 blocks, 0 bytes) garbage (have>want=0, old)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 storage class "default": 3357540 replicas (3357540 blocks, 199211579243382 bytes) desired
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 storage class "default": 0 replicas (0 blocks, 0 bytes) short
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 storage class "default": 154 replicas (150 blocks, 1017715394 bytes) surplus
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 storage class "default": 0 replicas (0 blocks, 0 bytes) unachievable
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 3357540 replicas (3357540 blocks, 199211579243382 bytes) total commitment (excluding unreferenced)
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 3357694 replicas (3357540 blocks, 199212596958776 bytes) total usage
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): ChangeSet{Pulls:326784, Trashes:0}
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): ChangeSet{Pulls:1427, Trashes:0}
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): ChangeSet{Pulls:1480, Trashes:0}
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): ChangeSet{Pulls:343, Trashes:0}
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 Replication level distribution (counting N replicas on a single server as N):
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57  0:       0
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57  1: 3357390 ###########################################################
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57  2:     146 ###################
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57  3:       4 ######
May 29 19:47:58 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:57 ===
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): send trash list: start
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-oynapdlh4hzydcf (keep0.dhhck.arvadosapi.com:25107, s3): send trash list: took 780.98µs
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-pkwwh8mhe0qgmu6 (keep2.dhhck.arvadosapi.com:25107, s3): send trash list: took 1.555394ms
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-jt6xs3d6d531oaa (keep1.dhhck.arvadosapi.com:25107, s3): send trash list: took 1.537235ms
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 dhhck-bi6l4-u6ez2qmdvdde1xc (keep3.dhhck.arvadosapi.com:25107, s3): send trash list: took 1.595105ms
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 Run: took 13m43.311678264s
May 29 19:47:59 dhhck.arvadosapi.com keep-balance[21398]: 2018/05/29 19:47:59 run succeeded

So from a functional perspective, this LGTM.

Actions

Copy link

#13

Updated by Tom Clegg almost 6 years ago

Status changed from New to Resolved
% Done changed from 0 to 100

Applied in changeset arvados|05fdfcec08e280a03c532a1a98b3aeebc716f6eb.

Actions

Copy link

#14

Updated by Tom Morris over 5 years ago

Release set to 13

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

Arvados

Custom queries

Bug #13513

[keep-balance] hang on ComputeChangeSets

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Tom Morris almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Tom Clegg almost 6 years ago

Updated by Tom Clegg almost 6 years ago

Updated by Ward Vandewege almost 6 years ago

Updated by Tom Clegg almost 6 years ago

Updated by Tom Morris over 5 years ago