本站源代码
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

676 lines
17KB

  1. // Copyright 2011 Google Inc. All rights reserved.
  2. // Use of this source code is governed by the Apache 2.0
  3. // license that can be found in the LICENSE file.
  4. // +build !appengine
  5. package internal
  6. import (
  7. "bytes"
  8. "errors"
  9. "fmt"
  10. "io/ioutil"
  11. "log"
  12. "net"
  13. "net/http"
  14. "net/url"
  15. "os"
  16. "runtime"
  17. "strconv"
  18. "strings"
  19. "sync"
  20. "sync/atomic"
  21. "time"
  22. "github.com/golang/protobuf/proto"
  23. netcontext "golang.org/x/net/context"
  24. basepb "google.golang.org/appengine/internal/base"
  25. logpb "google.golang.org/appengine/internal/log"
  26. remotepb "google.golang.org/appengine/internal/remote_api"
  27. )
  28. const (
  29. apiPath = "/rpc_http"
  30. defaultTicketSuffix = "/default.20150612t184001.0"
  31. )
  32. var (
  33. // Incoming headers.
  34. ticketHeader = http.CanonicalHeaderKey("X-AppEngine-API-Ticket")
  35. dapperHeader = http.CanonicalHeaderKey("X-Google-DapperTraceInfo")
  36. traceHeader = http.CanonicalHeaderKey("X-Cloud-Trace-Context")
  37. curNamespaceHeader = http.CanonicalHeaderKey("X-AppEngine-Current-Namespace")
  38. userIPHeader = http.CanonicalHeaderKey("X-AppEngine-User-IP")
  39. remoteAddrHeader = http.CanonicalHeaderKey("X-AppEngine-Remote-Addr")
  40. devRequestIdHeader = http.CanonicalHeaderKey("X-Appengine-Dev-Request-Id")
  41. // Outgoing headers.
  42. apiEndpointHeader = http.CanonicalHeaderKey("X-Google-RPC-Service-Endpoint")
  43. apiEndpointHeaderValue = []string{"app-engine-apis"}
  44. apiMethodHeader = http.CanonicalHeaderKey("X-Google-RPC-Service-Method")
  45. apiMethodHeaderValue = []string{"/VMRemoteAPI.CallRemoteAPI"}
  46. apiDeadlineHeader = http.CanonicalHeaderKey("X-Google-RPC-Service-Deadline")
  47. apiContentType = http.CanonicalHeaderKey("Content-Type")
  48. apiContentTypeValue = []string{"application/octet-stream"}
  49. logFlushHeader = http.CanonicalHeaderKey("X-AppEngine-Log-Flush-Count")
  50. apiHTTPClient = &http.Client{
  51. Transport: &http.Transport{
  52. Proxy: http.ProxyFromEnvironment,
  53. Dial: limitDial,
  54. },
  55. }
  56. defaultTicketOnce sync.Once
  57. defaultTicket string
  58. backgroundContextOnce sync.Once
  59. backgroundContext netcontext.Context
  60. )
  61. func apiURL() *url.URL {
  62. host, port := "appengine.googleapis.internal", "10001"
  63. if h := os.Getenv("API_HOST"); h != "" {
  64. host = h
  65. }
  66. if p := os.Getenv("API_PORT"); p != "" {
  67. port = p
  68. }
  69. return &url.URL{
  70. Scheme: "http",
  71. Host: host + ":" + port,
  72. Path: apiPath,
  73. }
  74. }
  75. func handleHTTP(w http.ResponseWriter, r *http.Request) {
  76. c := &context{
  77. req: r,
  78. outHeader: w.Header(),
  79. apiURL: apiURL(),
  80. }
  81. r = r.WithContext(withContext(r.Context(), c))
  82. c.req = r
  83. stopFlushing := make(chan int)
  84. // Patch up RemoteAddr so it looks reasonable.
  85. if addr := r.Header.Get(userIPHeader); addr != "" {
  86. r.RemoteAddr = addr
  87. } else if addr = r.Header.Get(remoteAddrHeader); addr != "" {
  88. r.RemoteAddr = addr
  89. } else {
  90. // Should not normally reach here, but pick a sensible default anyway.
  91. r.RemoteAddr = "127.0.0.1"
  92. }
  93. // The address in the headers will most likely be of these forms:
  94. // 123.123.123.123
  95. // 2001:db8::1
  96. // net/http.Request.RemoteAddr is specified to be in "IP:port" form.
  97. if _, _, err := net.SplitHostPort(r.RemoteAddr); err != nil {
  98. // Assume the remote address is only a host; add a default port.
  99. r.RemoteAddr = net.JoinHostPort(r.RemoteAddr, "80")
  100. }
  101. // Start goroutine responsible for flushing app logs.
  102. // This is done after adding c to ctx.m (and stopped before removing it)
  103. // because flushing logs requires making an API call.
  104. go c.logFlusher(stopFlushing)
  105. executeRequestSafely(c, r)
  106. c.outHeader = nil // make sure header changes aren't respected any more
  107. stopFlushing <- 1 // any logging beyond this point will be dropped
  108. // Flush any pending logs asynchronously.
  109. c.pendingLogs.Lock()
  110. flushes := c.pendingLogs.flushes
  111. if len(c.pendingLogs.lines) > 0 {
  112. flushes++
  113. }
  114. c.pendingLogs.Unlock()
  115. flushed := make(chan struct{})
  116. go func() {
  117. defer close(flushed)
  118. // Force a log flush, because with very short requests we
  119. // may not ever flush logs.
  120. c.flushLog(true)
  121. }()
  122. w.Header().Set(logFlushHeader, strconv.Itoa(flushes))
  123. // Avoid nil Write call if c.Write is never called.
  124. if c.outCode != 0 {
  125. w.WriteHeader(c.outCode)
  126. }
  127. if c.outBody != nil {
  128. w.Write(c.outBody)
  129. }
  130. // Wait for the last flush to complete before returning,
  131. // otherwise the security ticket will not be valid.
  132. <-flushed
  133. }
  134. func executeRequestSafely(c *context, r *http.Request) {
  135. defer func() {
  136. if x := recover(); x != nil {
  137. logf(c, 4, "%s", renderPanic(x)) // 4 == critical
  138. c.outCode = 500
  139. }
  140. }()
  141. http.DefaultServeMux.ServeHTTP(c, r)
  142. }
  143. func renderPanic(x interface{}) string {
  144. buf := make([]byte, 16<<10) // 16 KB should be plenty
  145. buf = buf[:runtime.Stack(buf, false)]
  146. // Remove the first few stack frames:
  147. // this func
  148. // the recover closure in the caller
  149. // That will root the stack trace at the site of the panic.
  150. const (
  151. skipStart = "internal.renderPanic"
  152. skipFrames = 2
  153. )
  154. start := bytes.Index(buf, []byte(skipStart))
  155. p := start
  156. for i := 0; i < skipFrames*2 && p+1 < len(buf); i++ {
  157. p = bytes.IndexByte(buf[p+1:], '\n') + p + 1
  158. if p < 0 {
  159. break
  160. }
  161. }
  162. if p >= 0 {
  163. // buf[start:p+1] is the block to remove.
  164. // Copy buf[p+1:] over buf[start:] and shrink buf.
  165. copy(buf[start:], buf[p+1:])
  166. buf = buf[:len(buf)-(p+1-start)]
  167. }
  168. // Add panic heading.
  169. head := fmt.Sprintf("panic: %v\n\n", x)
  170. if len(head) > len(buf) {
  171. // Extremely unlikely to happen.
  172. return head
  173. }
  174. copy(buf[len(head):], buf)
  175. copy(buf, head)
  176. return string(buf)
  177. }
  178. // context represents the context of an in-flight HTTP request.
  179. // It implements the appengine.Context and http.ResponseWriter interfaces.
  180. type context struct {
  181. req *http.Request
  182. outCode int
  183. outHeader http.Header
  184. outBody []byte
  185. pendingLogs struct {
  186. sync.Mutex
  187. lines []*logpb.UserAppLogLine
  188. flushes int
  189. }
  190. apiURL *url.URL
  191. }
  192. var contextKey = "holds a *context"
  193. // jointContext joins two contexts in a superficial way.
  194. // It takes values and timeouts from a base context, and only values from another context.
  195. type jointContext struct {
  196. base netcontext.Context
  197. valuesOnly netcontext.Context
  198. }
  199. func (c jointContext) Deadline() (time.Time, bool) {
  200. return c.base.Deadline()
  201. }
  202. func (c jointContext) Done() <-chan struct{} {
  203. return c.base.Done()
  204. }
  205. func (c jointContext) Err() error {
  206. return c.base.Err()
  207. }
  208. func (c jointContext) Value(key interface{}) interface{} {
  209. if val := c.base.Value(key); val != nil {
  210. return val
  211. }
  212. return c.valuesOnly.Value(key)
  213. }
  214. // fromContext returns the App Engine context or nil if ctx is not
  215. // derived from an App Engine context.
  216. func fromContext(ctx netcontext.Context) *context {
  217. c, _ := ctx.Value(&contextKey).(*context)
  218. return c
  219. }
  220. func withContext(parent netcontext.Context, c *context) netcontext.Context {
  221. ctx := netcontext.WithValue(parent, &contextKey, c)
  222. if ns := c.req.Header.Get(curNamespaceHeader); ns != "" {
  223. ctx = withNamespace(ctx, ns)
  224. }
  225. return ctx
  226. }
  227. func toContext(c *context) netcontext.Context {
  228. return withContext(netcontext.Background(), c)
  229. }
  230. func IncomingHeaders(ctx netcontext.Context) http.Header {
  231. if c := fromContext(ctx); c != nil {
  232. return c.req.Header
  233. }
  234. return nil
  235. }
  236. func ReqContext(req *http.Request) netcontext.Context {
  237. return req.Context()
  238. }
  239. func WithContext(parent netcontext.Context, req *http.Request) netcontext.Context {
  240. return jointContext{
  241. base: parent,
  242. valuesOnly: req.Context(),
  243. }
  244. }
  245. // DefaultTicket returns a ticket used for background context or dev_appserver.
  246. func DefaultTicket() string {
  247. defaultTicketOnce.Do(func() {
  248. if IsDevAppServer() {
  249. defaultTicket = "testapp" + defaultTicketSuffix
  250. return
  251. }
  252. appID := partitionlessAppID()
  253. escAppID := strings.Replace(strings.Replace(appID, ":", "_", -1), ".", "_", -1)
  254. majVersion := VersionID(nil)
  255. if i := strings.Index(majVersion, "."); i > 0 {
  256. majVersion = majVersion[:i]
  257. }
  258. defaultTicket = fmt.Sprintf("%s/%s.%s.%s", escAppID, ModuleName(nil), majVersion, InstanceID())
  259. })
  260. return defaultTicket
  261. }
  262. func BackgroundContext() netcontext.Context {
  263. backgroundContextOnce.Do(func() {
  264. // Compute background security ticket.
  265. ticket := DefaultTicket()
  266. c := &context{
  267. req: &http.Request{
  268. Header: http.Header{
  269. ticketHeader: []string{ticket},
  270. },
  271. },
  272. apiURL: apiURL(),
  273. }
  274. backgroundContext = toContext(c)
  275. // TODO(dsymonds): Wire up the shutdown handler to do a final flush.
  276. go c.logFlusher(make(chan int))
  277. })
  278. return backgroundContext
  279. }
  280. // RegisterTestRequest registers the HTTP request req for testing, such that
  281. // any API calls are sent to the provided URL. It returns a closure to delete
  282. // the registration.
  283. // It should only be used by aetest package.
  284. func RegisterTestRequest(req *http.Request, apiURL *url.URL, decorate func(netcontext.Context) netcontext.Context) (*http.Request, func()) {
  285. c := &context{
  286. req: req,
  287. apiURL: apiURL,
  288. }
  289. ctx := withContext(decorate(req.Context()), c)
  290. req = req.WithContext(ctx)
  291. c.req = req
  292. return req, func() {}
  293. }
  294. var errTimeout = &CallError{
  295. Detail: "Deadline exceeded",
  296. Code: int32(remotepb.RpcError_CANCELLED),
  297. Timeout: true,
  298. }
  299. func (c *context) Header() http.Header { return c.outHeader }
  300. // Copied from $GOROOT/src/pkg/net/http/transfer.go. Some response status
  301. // codes do not permit a response body (nor response entity headers such as
  302. // Content-Length, Content-Type, etc).
  303. func bodyAllowedForStatus(status int) bool {
  304. switch {
  305. case status >= 100 && status <= 199:
  306. return false
  307. case status == 204:
  308. return false
  309. case status == 304:
  310. return false
  311. }
  312. return true
  313. }
  314. func (c *context) Write(b []byte) (int, error) {
  315. if c.outCode == 0 {
  316. c.WriteHeader(http.StatusOK)
  317. }
  318. if len(b) > 0 && !bodyAllowedForStatus(c.outCode) {
  319. return 0, http.ErrBodyNotAllowed
  320. }
  321. c.outBody = append(c.outBody, b...)
  322. return len(b), nil
  323. }
  324. func (c *context) WriteHeader(code int) {
  325. if c.outCode != 0 {
  326. logf(c, 3, "WriteHeader called multiple times on request.") // error level
  327. return
  328. }
  329. c.outCode = code
  330. }
  331. func (c *context) post(body []byte, timeout time.Duration) (b []byte, err error) {
  332. hreq := &http.Request{
  333. Method: "POST",
  334. URL: c.apiURL,
  335. Header: http.Header{
  336. apiEndpointHeader: apiEndpointHeaderValue,
  337. apiMethodHeader: apiMethodHeaderValue,
  338. apiContentType: apiContentTypeValue,
  339. apiDeadlineHeader: []string{strconv.FormatFloat(timeout.Seconds(), 'f', -1, 64)},
  340. },
  341. Body: ioutil.NopCloser(bytes.NewReader(body)),
  342. ContentLength: int64(len(body)),
  343. Host: c.apiURL.Host,
  344. }
  345. if info := c.req.Header.Get(dapperHeader); info != "" {
  346. hreq.Header.Set(dapperHeader, info)
  347. }
  348. if info := c.req.Header.Get(traceHeader); info != "" {
  349. hreq.Header.Set(traceHeader, info)
  350. }
  351. tr := apiHTTPClient.Transport.(*http.Transport)
  352. var timedOut int32 // atomic; set to 1 if timed out
  353. t := time.AfterFunc(timeout, func() {
  354. atomic.StoreInt32(&timedOut, 1)
  355. tr.CancelRequest(hreq)
  356. })
  357. defer t.Stop()
  358. defer func() {
  359. // Check if timeout was exceeded.
  360. if atomic.LoadInt32(&timedOut) != 0 {
  361. err = errTimeout
  362. }
  363. }()
  364. hresp, err := apiHTTPClient.Do(hreq)
  365. if err != nil {
  366. return nil, &CallError{
  367. Detail: fmt.Sprintf("service bridge HTTP failed: %v", err),
  368. Code: int32(remotepb.RpcError_UNKNOWN),
  369. }
  370. }
  371. defer hresp.Body.Close()
  372. hrespBody, err := ioutil.ReadAll(hresp.Body)
  373. if hresp.StatusCode != 200 {
  374. return nil, &CallError{
  375. Detail: fmt.Sprintf("service bridge returned HTTP %d (%q)", hresp.StatusCode, hrespBody),
  376. Code: int32(remotepb.RpcError_UNKNOWN),
  377. }
  378. }
  379. if err != nil {
  380. return nil, &CallError{
  381. Detail: fmt.Sprintf("service bridge response bad: %v", err),
  382. Code: int32(remotepb.RpcError_UNKNOWN),
  383. }
  384. }
  385. return hrespBody, nil
  386. }
  387. func Call(ctx netcontext.Context, service, method string, in, out proto.Message) error {
  388. if ns := NamespaceFromContext(ctx); ns != "" {
  389. if fn, ok := NamespaceMods[service]; ok {
  390. fn(in, ns)
  391. }
  392. }
  393. if f, ctx, ok := callOverrideFromContext(ctx); ok {
  394. return f(ctx, service, method, in, out)
  395. }
  396. // Handle already-done contexts quickly.
  397. select {
  398. case <-ctx.Done():
  399. return ctx.Err()
  400. default:
  401. }
  402. c := fromContext(ctx)
  403. if c == nil {
  404. // Give a good error message rather than a panic lower down.
  405. return errNotAppEngineContext
  406. }
  407. // Apply transaction modifications if we're in a transaction.
  408. if t := transactionFromContext(ctx); t != nil {
  409. if t.finished {
  410. return errors.New("transaction context has expired")
  411. }
  412. applyTransaction(in, &t.transaction)
  413. }
  414. // Default RPC timeout is 60s.
  415. timeout := 60 * time.Second
  416. if deadline, ok := ctx.Deadline(); ok {
  417. timeout = deadline.Sub(time.Now())
  418. }
  419. data, err := proto.Marshal(in)
  420. if err != nil {
  421. return err
  422. }
  423. ticket := c.req.Header.Get(ticketHeader)
  424. // Use a test ticket under test environment.
  425. if ticket == "" {
  426. if appid := ctx.Value(&appIDOverrideKey); appid != nil {
  427. ticket = appid.(string) + defaultTicketSuffix
  428. }
  429. }
  430. // Fall back to use background ticket when the request ticket is not available in Flex or dev_appserver.
  431. if ticket == "" {
  432. ticket = DefaultTicket()
  433. }
  434. if dri := c.req.Header.Get(devRequestIdHeader); IsDevAppServer() && dri != "" {
  435. ticket = dri
  436. }
  437. req := &remotepb.Request{
  438. ServiceName: &service,
  439. Method: &method,
  440. Request: data,
  441. RequestId: &ticket,
  442. }
  443. hreqBody, err := proto.Marshal(req)
  444. if err != nil {
  445. return err
  446. }
  447. hrespBody, err := c.post(hreqBody, timeout)
  448. if err != nil {
  449. return err
  450. }
  451. res := &remotepb.Response{}
  452. if err := proto.Unmarshal(hrespBody, res); err != nil {
  453. return err
  454. }
  455. if res.RpcError != nil {
  456. ce := &CallError{
  457. Detail: res.RpcError.GetDetail(),
  458. Code: *res.RpcError.Code,
  459. }
  460. switch remotepb.RpcError_ErrorCode(ce.Code) {
  461. case remotepb.RpcError_CANCELLED, remotepb.RpcError_DEADLINE_EXCEEDED:
  462. ce.Timeout = true
  463. }
  464. return ce
  465. }
  466. if res.ApplicationError != nil {
  467. return &APIError{
  468. Service: *req.ServiceName,
  469. Detail: res.ApplicationError.GetDetail(),
  470. Code: *res.ApplicationError.Code,
  471. }
  472. }
  473. if res.Exception != nil || res.JavaException != nil {
  474. // This shouldn't happen, but let's be defensive.
  475. return &CallError{
  476. Detail: "service bridge returned exception",
  477. Code: int32(remotepb.RpcError_UNKNOWN),
  478. }
  479. }
  480. return proto.Unmarshal(res.Response, out)
  481. }
  482. func (c *context) Request() *http.Request {
  483. return c.req
  484. }
  485. func (c *context) addLogLine(ll *logpb.UserAppLogLine) {
  486. // Truncate long log lines.
  487. // TODO(dsymonds): Check if this is still necessary.
  488. const lim = 8 << 10
  489. if len(*ll.Message) > lim {
  490. suffix := fmt.Sprintf("...(length %d)", len(*ll.Message))
  491. ll.Message = proto.String((*ll.Message)[:lim-len(suffix)] + suffix)
  492. }
  493. c.pendingLogs.Lock()
  494. c.pendingLogs.lines = append(c.pendingLogs.lines, ll)
  495. c.pendingLogs.Unlock()
  496. }
  497. var logLevelName = map[int64]string{
  498. 0: "DEBUG",
  499. 1: "INFO",
  500. 2: "WARNING",
  501. 3: "ERROR",
  502. 4: "CRITICAL",
  503. }
  504. func logf(c *context, level int64, format string, args ...interface{}) {
  505. if c == nil {
  506. panic("not an App Engine context")
  507. }
  508. s := fmt.Sprintf(format, args...)
  509. s = strings.TrimRight(s, "\n") // Remove any trailing newline characters.
  510. c.addLogLine(&logpb.UserAppLogLine{
  511. TimestampUsec: proto.Int64(time.Now().UnixNano() / 1e3),
  512. Level: &level,
  513. Message: &s,
  514. })
  515. // Only duplicate log to stderr if not running on App Engine second generation
  516. if !IsSecondGen() {
  517. log.Print(logLevelName[level] + ": " + s)
  518. }
  519. }
  520. // flushLog attempts to flush any pending logs to the appserver.
  521. // It should not be called concurrently.
  522. func (c *context) flushLog(force bool) (flushed bool) {
  523. c.pendingLogs.Lock()
  524. // Grab up to 30 MB. We can get away with up to 32 MB, but let's be cautious.
  525. n, rem := 0, 30<<20
  526. for ; n < len(c.pendingLogs.lines); n++ {
  527. ll := c.pendingLogs.lines[n]
  528. // Each log line will require about 3 bytes of overhead.
  529. nb := proto.Size(ll) + 3
  530. if nb > rem {
  531. break
  532. }
  533. rem -= nb
  534. }
  535. lines := c.pendingLogs.lines[:n]
  536. c.pendingLogs.lines = c.pendingLogs.lines[n:]
  537. c.pendingLogs.Unlock()
  538. if len(lines) == 0 && !force {
  539. // Nothing to flush.
  540. return false
  541. }
  542. rescueLogs := false
  543. defer func() {
  544. if rescueLogs {
  545. c.pendingLogs.Lock()
  546. c.pendingLogs.lines = append(lines, c.pendingLogs.lines...)
  547. c.pendingLogs.Unlock()
  548. }
  549. }()
  550. buf, err := proto.Marshal(&logpb.UserAppLogGroup{
  551. LogLine: lines,
  552. })
  553. if err != nil {
  554. log.Printf("internal.flushLog: marshaling UserAppLogGroup: %v", err)
  555. rescueLogs = true
  556. return false
  557. }
  558. req := &logpb.FlushRequest{
  559. Logs: buf,
  560. }
  561. res := &basepb.VoidProto{}
  562. c.pendingLogs.Lock()
  563. c.pendingLogs.flushes++
  564. c.pendingLogs.Unlock()
  565. if err := Call(toContext(c), "logservice", "Flush", req, res); err != nil {
  566. log.Printf("internal.flushLog: Flush RPC: %v", err)
  567. rescueLogs = true
  568. return false
  569. }
  570. return true
  571. }
  572. const (
  573. // Log flushing parameters.
  574. flushInterval = 1 * time.Second
  575. forceFlushInterval = 60 * time.Second
  576. )
  577. func (c *context) logFlusher(stop <-chan int) {
  578. lastFlush := time.Now()
  579. tick := time.NewTicker(flushInterval)
  580. for {
  581. select {
  582. case <-stop:
  583. // Request finished.
  584. tick.Stop()
  585. return
  586. case <-tick.C:
  587. force := time.Now().Sub(lastFlush) > forceFlushInterval
  588. if c.flushLog(force) {
  589. lastFlush = time.Now()
  590. }
  591. }
  592. }
  593. }
  594. func ContextForTesting(req *http.Request) netcontext.Context {
  595. return toContext(&context{req: req})
  596. }
上海开阖软件有限公司 沪ICP备12045867号-1