closes #7162
[arvados.git] / services / datamanager / keep / keep.go
1 /* Deals with getting Keep Server blocks from API Server and Keep Servers. */
2
3 package keep
4
5 import (
6         "bufio"
7         "encoding/json"
8         "errors"
9         "fmt"
10         "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
11         "git.curoverse.com/arvados.git/sdk/go/blockdigest"
12         "git.curoverse.com/arvados.git/sdk/go/keepclient"
13         "git.curoverse.com/arvados.git/sdk/go/logger"
14         "git.curoverse.com/arvados.git/services/datamanager/loggerutil"
15         "io"
16         "io/ioutil"
17         "log"
18         "net/http"
19         "strconv"
20         "strings"
21         "time"
22 )
23
24 // ServerAddress struct
25 type ServerAddress struct {
26         SSL         bool   `json:service_ssl_flag`
27         Host        string `json:"service_host"`
28         Port        int    `json:"service_port"`
29         UUID        string `json:"uuid"`
30         ServiceType string `json:"service_type"`
31 }
32
33 // BlockInfo is info about a particular block returned by the server
34 type BlockInfo struct {
35         Digest blockdigest.DigestWithSize
36         Mtime  int64 // TODO(misha): Replace this with a timestamp.
37 }
38
39 // BlockServerInfo is info about a specified block given by a server
40 type BlockServerInfo struct {
41         ServerIndex int
42         Mtime       int64 // TODO(misha): Replace this with a timestamp.
43 }
44
45 // ServerContents struct
46 type ServerContents struct {
47         BlockDigestToInfo map[blockdigest.DigestWithSize]BlockInfo
48 }
49
50 // ServerResponse struct
51 type ServerResponse struct {
52         Address  ServerAddress
53         Contents ServerContents
54 }
55
56 // ReadServers struct
57 type ReadServers struct {
58         ReadAllServers           bool
59         KeepServerIndexToAddress []ServerAddress
60         KeepServerAddressToIndex map[ServerAddress]int
61         ServerToContents         map[ServerAddress]ServerContents
62         BlockToServers           map[blockdigest.DigestWithSize][]BlockServerInfo
63         BlockReplicationCounts   map[int]int
64 }
65
66 // GetKeepServersParams struct
67 type GetKeepServersParams struct {
68         Client arvadosclient.ArvadosClient
69         Logger *logger.Logger
70         Limit  int
71 }
72
73 // ServiceList consists of the addresses of all the available kee servers
74 type ServiceList struct {
75         ItemsAvailable int             `json:"items_available"`
76         KeepServers    []ServerAddress `json:"items"`
77 }
78
79 // String
80 // TODO(misha): Change this to include the UUID as well.
81 func (s ServerAddress) String() string {
82         return s.URL()
83 }
84
85 // URL of the keep server
86 func (s ServerAddress) URL() string {
87         if s.SSL {
88                 return fmt.Sprintf("https://%s:%d", s.Host, s.Port)
89         }
90         return fmt.Sprintf("http://%s:%d", s.Host, s.Port)
91 }
92
93 // GetKeepServersAndSummarize gets keep servers from api
94 func GetKeepServersAndSummarize(params GetKeepServersParams) (results ReadServers) {
95         results = GetKeepServers(params)
96         log.Printf("Returned %d keep disks", len(results.ServerToContents))
97
98         results.Summarize(params.Logger)
99         log.Printf("Replication level distribution: %v",
100                 results.BlockReplicationCounts)
101
102         return
103 }
104
105 // GetKeepServers from api server
106 func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
107         sdkParams := arvadosclient.Dict{
108                 "filters": [][]string{[]string{"service_type", "!=", "proxy"}},
109         }
110         if params.Limit > 0 {
111                 sdkParams["limit"] = params.Limit
112         }
113
114         var sdkResponse ServiceList
115         err := params.Client.List("keep_services", sdkParams, &sdkResponse)
116
117         if err != nil {
118                 loggerutil.FatalWithMessage(params.Logger,
119                         fmt.Sprintf("Error requesting keep disks from API server: %v", err))
120         }
121
122         // Currently, only "disk" types are supported. Stop if any other service types are found.
123         for _, server := range sdkResponse.KeepServers {
124                 if server.ServiceType != "disk" {
125                         loggerutil.FatalWithMessage(params.Logger,
126                                 fmt.Sprintf("Unsupported service type %q found for: %v", server.ServiceType, server))
127                 }
128         }
129
130         if params.Logger != nil {
131                 params.Logger.Update(func(p map[string]interface{}, e map[string]interface{}) {
132                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
133                         keepInfo["num_keep_servers_available"] = sdkResponse.ItemsAvailable
134                         keepInfo["num_keep_servers_received"] = len(sdkResponse.KeepServers)
135                         keepInfo["keep_servers"] = sdkResponse.KeepServers
136                 })
137         }
138
139         log.Printf("Received keep services list: %+v", sdkResponse)
140
141         if len(sdkResponse.KeepServers) < sdkResponse.ItemsAvailable {
142                 loggerutil.FatalWithMessage(params.Logger,
143                         fmt.Sprintf("Did not receive all available keep servers: %+v", sdkResponse))
144         }
145
146         results.KeepServerIndexToAddress = sdkResponse.KeepServers
147         results.KeepServerAddressToIndex = make(map[ServerAddress]int)
148         for i, address := range results.KeepServerIndexToAddress {
149                 results.KeepServerAddressToIndex[address] = i
150         }
151
152         log.Printf("Got Server Addresses: %v", results)
153
154         // Send off all the index requests concurrently
155         responseChan := make(chan ServerResponse)
156         for _, keepServer := range sdkResponse.KeepServers {
157                 // The above keepsServer variable is reused for each iteration, so
158                 // it would be shared across all goroutines. This would result in
159                 // us querying one server n times instead of n different servers
160                 // as we intended. To avoid this we add it as an explicit
161                 // parameter which gets copied. This bug and solution is described
162                 // in https://golang.org/doc/effective_go.html#channels
163                 go func(keepServer ServerAddress) {
164                         responseChan <- GetServerContents(params.Logger,
165                                 keepServer,
166                                 params.Client)
167                 }(keepServer)
168         }
169
170         results.ServerToContents = make(map[ServerAddress]ServerContents)
171         results.BlockToServers = make(map[blockdigest.DigestWithSize][]BlockServerInfo)
172
173         // Read all the responses
174         for i := range sdkResponse.KeepServers {
175                 _ = i // Here to prevent go from complaining.
176                 response := <-responseChan
177                 log.Printf("Received channel response from %v containing %d files",
178                         response.Address,
179                         len(response.Contents.BlockDigestToInfo))
180                 results.ServerToContents[response.Address] = response.Contents
181                 serverIndex := results.KeepServerAddressToIndex[response.Address]
182                 for _, blockInfo := range response.Contents.BlockDigestToInfo {
183                         results.BlockToServers[blockInfo.Digest] = append(
184                                 results.BlockToServers[blockInfo.Digest],
185                                 BlockServerInfo{ServerIndex: serverIndex,
186                                         Mtime: blockInfo.Mtime})
187                 }
188         }
189         return
190 }
191
192 // GetServerContents of the keep server
193 func GetServerContents(arvLogger *logger.Logger,
194         keepServer ServerAddress,
195         arv arvadosclient.ArvadosClient) (response ServerResponse) {
196
197         GetServerStatus(arvLogger, keepServer, arv)
198
199         req := CreateIndexRequest(arvLogger, keepServer, arv)
200         resp, err := arv.Client.Do(req)
201         if err != nil {
202                 loggerutil.FatalWithMessage(arvLogger,
203                         fmt.Sprintf("Error fetching %s: %v. Response was %+v",
204                                 req.URL.String(),
205                                 err,
206                                 resp))
207         }
208
209         return ReadServerResponse(arvLogger, keepServer, resp)
210 }
211
212 // GetServerStatus get keep server status by invoking /status.json
213 func GetServerStatus(arvLogger *logger.Logger,
214         keepServer ServerAddress,
215         arv arvadosclient.ArvadosClient) {
216         url := fmt.Sprintf("http://%s:%d/status.json",
217                 keepServer.Host,
218                 keepServer.Port)
219
220         if arvLogger != nil {
221                 now := time.Now()
222                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
223                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
224                         serverInfo := make(map[string]interface{})
225                         serverInfo["status_request_sent_at"] = now
226                         serverInfo["host"] = keepServer.Host
227                         serverInfo["port"] = keepServer.Port
228
229                         keepInfo[keepServer.UUID] = serverInfo
230                 })
231         }
232
233         resp, err := arv.Client.Get(url)
234         if err != nil {
235                 loggerutil.FatalWithMessage(arvLogger,
236                         fmt.Sprintf("Error getting keep status from %s: %v", url, err))
237         } else if resp.StatusCode != 200 {
238                 loggerutil.FatalWithMessage(arvLogger,
239                         fmt.Sprintf("Received error code %d in response to request "+
240                                 "for %s status: %s",
241                                 resp.StatusCode, url, resp.Status))
242         }
243
244         var keepStatus map[string]interface{}
245         decoder := json.NewDecoder(resp.Body)
246         decoder.UseNumber()
247         err = decoder.Decode(&keepStatus)
248         if err != nil {
249                 loggerutil.FatalWithMessage(arvLogger,
250                         fmt.Sprintf("Error decoding keep status from %s: %v", url, err))
251         }
252
253         if arvLogger != nil {
254                 now := time.Now()
255                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
256                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
257                         serverInfo := keepInfo[keepServer.UUID].(map[string]interface{})
258                         serverInfo["status_response_processed_at"] = now
259                         serverInfo["status"] = keepStatus
260                 })
261         }
262 }
263
264 // CreateIndexRequest to the keep server
265 func CreateIndexRequest(arvLogger *logger.Logger,
266         keepServer ServerAddress,
267         arv arvadosclient.ArvadosClient) (req *http.Request) {
268         url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
269         log.Println("About to fetch keep server contents from " + url)
270
271         if arvLogger != nil {
272                 now := time.Now()
273                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
274                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
275                         serverInfo := keepInfo[keepServer.UUID].(map[string]interface{})
276                         serverInfo["index_request_sent_at"] = now
277                 })
278         }
279
280         req, err := http.NewRequest("GET", url, nil)
281         if err != nil {
282                 loggerutil.FatalWithMessage(arvLogger,
283                         fmt.Sprintf("Error building http request for %s: %v", url, err))
284         }
285
286         req.Header.Add("Authorization", "OAuth2 "+arv.ApiToken)
287         return
288 }
289
290 // ReadServerResponse reads reasponse from keep server
291 func ReadServerResponse(arvLogger *logger.Logger,
292         keepServer ServerAddress,
293         resp *http.Response) (response ServerResponse) {
294
295         if resp.StatusCode != 200 {
296                 loggerutil.FatalWithMessage(arvLogger,
297                         fmt.Sprintf("Received error code %d in response to request "+
298                                 "for %s index: %s",
299                                 resp.StatusCode, keepServer.String(), resp.Status))
300         }
301
302         if arvLogger != nil {
303                 now := time.Now()
304                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
305                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
306                         serverInfo := keepInfo[keepServer.UUID].(map[string]interface{})
307                         serverInfo["index_response_received_at"] = now
308                 })
309         }
310
311         response.Address = keepServer
312         response.Contents.BlockDigestToInfo =
313                 make(map[blockdigest.DigestWithSize]BlockInfo)
314         reader := bufio.NewReader(resp.Body)
315         numLines, numDuplicates, numSizeDisagreements := 0, 0, 0
316         for {
317                 numLines++
318                 line, err := reader.ReadString('\n')
319                 if err == io.EOF {
320                         loggerutil.FatalWithMessage(arvLogger,
321                                 fmt.Sprintf("Index from %s truncated at line %d",
322                                         keepServer.String(), numLines))
323                 } else if err != nil {
324                         loggerutil.FatalWithMessage(arvLogger,
325                                 fmt.Sprintf("Error reading index response from %s at line %d: %v",
326                                         keepServer.String(), numLines, err))
327                 }
328                 if line == "\n" {
329                         if _, err := reader.Peek(1); err == nil {
330                                 extra, _ := reader.ReadString('\n')
331                                 loggerutil.FatalWithMessage(arvLogger,
332                                         fmt.Sprintf("Index from %s had trailing data at line %d after EOF marker: %s",
333                                                 keepServer.String(), numLines+1, extra))
334                         } else if err != io.EOF {
335                                 loggerutil.FatalWithMessage(arvLogger,
336                                         fmt.Sprintf("Index from %s had read error after EOF marker at line %d: %v",
337                                                 keepServer.String(), numLines, err))
338                         }
339                         numLines--
340                         break
341                 }
342                 blockInfo, err := parseBlockInfoFromIndexLine(line)
343                 if err != nil {
344                         loggerutil.FatalWithMessage(arvLogger,
345                                 fmt.Sprintf("Error parsing BlockInfo from index line "+
346                                         "received from %s: %v",
347                                         keepServer.String(),
348                                         err))
349                 }
350
351                 if storedBlock, ok := response.Contents.BlockDigestToInfo[blockInfo.Digest]; ok {
352                         // This server returned multiple lines containing the same block digest.
353                         numDuplicates++
354                         // Keep the block that's newer.
355                         if storedBlock.Mtime < blockInfo.Mtime {
356                                 response.Contents.BlockDigestToInfo[blockInfo.Digest] = blockInfo
357                         }
358                 } else {
359                         response.Contents.BlockDigestToInfo[blockInfo.Digest] = blockInfo
360                 }
361         }
362
363         log.Printf("%s index contained %d lines with %d duplicates with "+
364                 "%d size disagreements",
365                 keepServer.String(),
366                 numLines,
367                 numDuplicates,
368                 numSizeDisagreements)
369
370         if arvLogger != nil {
371                 now := time.Now()
372                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
373                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
374                         serverInfo := keepInfo[keepServer.UUID].(map[string]interface{})
375
376                         serverInfo["processing_finished_at"] = now
377                         serverInfo["lines_received"] = numLines
378                         serverInfo["duplicates_seen"] = numDuplicates
379                         serverInfo["size_disagreements_seen"] = numSizeDisagreements
380                 })
381         }
382         resp.Body.Close()
383         return
384 }
385
386 func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err error) {
387         tokens := strings.Fields(indexLine)
388         if len(tokens) != 2 {
389                 err = fmt.Errorf("Expected 2 tokens per line but received a "+
390                         "line containing %v instead.",
391                         tokens)
392         }
393
394         var locator blockdigest.BlockLocator
395         if locator, err = blockdigest.ParseBlockLocator(tokens[0]); err != nil {
396                 err = fmt.Errorf("%v Received error while parsing line \"%s\"",
397                         err, indexLine)
398                 return
399         }
400         if len(locator.Hints) > 0 {
401                 err = fmt.Errorf("Block locator in index line should not contain hints "+
402                         "but it does: %v",
403                         locator)
404                 return
405         }
406
407         blockInfo.Mtime, err = strconv.ParseInt(tokens[1], 10, 64)
408         if err != nil {
409                 return
410         }
411         blockInfo.Digest =
412                 blockdigest.DigestWithSize{Digest: locator.Digest,
413                         Size: uint32(locator.Size)}
414         return
415 }
416
417 // Summarize results from keep server
418 func (readServers *ReadServers) Summarize(arvLogger *logger.Logger) {
419         readServers.BlockReplicationCounts = make(map[int]int)
420         for _, infos := range readServers.BlockToServers {
421                 replication := len(infos)
422                 readServers.BlockReplicationCounts[replication]++
423         }
424
425         if arvLogger != nil {
426                 arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
427                         keepInfo := logger.GetOrCreateMap(p, "keep_info")
428                         keepInfo["distinct_blocks_stored"] = len(readServers.BlockToServers)
429                 })
430         }
431 }
432
433 // TrashRequest struct
434 type TrashRequest struct {
435         Locator    string `json:"locator"`
436         BlockMtime int64  `json:"block_mtime"`
437 }
438
439 // TrashList is an array of TrashRequest objects
440 type TrashList []TrashRequest
441
442 // SendTrashLists to trash queue
443 func SendTrashLists(kc *keepclient.KeepClient, spl map[string]TrashList) (errs []error) {
444         count := 0
445         barrier := make(chan error)
446
447         client := kc.Client
448
449         for url, v := range spl {
450                 count++
451                 log.Printf("Sending trash list to %v", url)
452
453                 go (func(url string, v TrashList) {
454                         pipeReader, pipeWriter := io.Pipe()
455                         go (func() {
456                                 enc := json.NewEncoder(pipeWriter)
457                                 enc.Encode(v)
458                                 pipeWriter.Close()
459                         })()
460
461                         req, err := http.NewRequest("PUT", fmt.Sprintf("%s/trash", url), pipeReader)
462                         if err != nil {
463                                 log.Printf("Error creating trash list request for %v error: %v", url, err.Error())
464                                 barrier <- err
465                                 return
466                         }
467
468                         req.Header.Add("Authorization", "OAuth2 "+kc.Arvados.ApiToken)
469
470                         // Make the request
471                         var resp *http.Response
472                         if resp, err = client.Do(req); err != nil {
473                                 log.Printf("Error sending trash list to %v error: %v", url, err.Error())
474                                 barrier <- err
475                                 return
476                         }
477
478                         log.Printf("Sent trash list to %v: response was HTTP %v", url, resp.Status)
479
480                         io.Copy(ioutil.Discard, resp.Body)
481                         resp.Body.Close()
482
483                         if resp.StatusCode != 200 {
484                                 barrier <- errors.New(fmt.Sprintf("Got HTTP code %v", resp.StatusCode))
485                         } else {
486                                 barrier <- nil
487                         }
488                 })(url, v)
489
490         }
491
492         for i := 0; i < count; i++ {
493                 b := <-barrier
494                 if b != nil {
495                         errs = append(errs, b)
496                 }
497         }
498
499         return errs
500 }