使用Jersey的Tracing功能

Jersey提供了一个tracing-support的测试module，用来演示它的tracing功能；

$ pwd
/Users/weli/projs/jersey/tests/integration/tracing-support

使用maven命令编译这个tracing-support测试样例：

$ mvn -Dmaven.test.skip=true clean install

运行这个样例：

$ mvn -q compile jetty:run

使用curl命令来查看tracing log：

$ curl -i http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method -H content-type:application/x-jersey-test --data '-=#[LKR]#=-' -H X-Jersey-Tracing-Threshold:SUMMARY -H accept:application/x-jersey-test -X POST

输出如下：

$ curl -i http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method -H content-type:application/x-jersey-test --data '-=#[LKR]#=-' -H X-Jersey-Tracing-Threshold:SUMMARY -H accept:application/x-jersey-test -X POST
HTTP/1.1 200 OK
Content-Length: 11
Content-Type: application/x-jersey-test
WriterInterceptor39: Tue, 08 May 2018 07:07:25 GMT
WriterInterceptor45: Tue, 08 May 2018 07:07:25 GMT
X-Jersey-Tracing-000: START       [ ---- /  ---- ms |  ---- %] baseUri=[http://localhost:9998/ALL/] requestUri=[http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method] method=[POST] authScheme=[n/a] accept=[application/x-jersey-test] accept-encoding=n/a accept-charset=n/a accept-language=n/a content-type=[application/x-jersey-test] content-length=[11]
X-Jersey-Tracing-001: PRE-MATCH   [ 0.28 /  7.65 ms |  0.14 %] PreMatchRequest summary: 3 filters
X-Jersey-Tracing-002: MATCH       [ 8.00 / 15.90 ms |  3.91 %] RequestMatching summary
X-Jersey-Tracing-003: REQ-FILTER  [ 0.01 / 16.34 ms |  0.00 %] Request summary: 2 filters
X-Jersey-Tracing-004: RI          [90.25 / 109.31 ms | 44.16 %] ReadFrom summary: 3 interceptors
X-Jersey-Tracing-005: INVOKE      [ 0.06 / 109.99 ms |  0.03 %] Resource [org.glassfish.jersey.tests.integration.tracing.SubResource @5d425bee] method=[public org.glassfish.jersey.tests.integration.tracing.Message org.glassfish.jersey.tests.integration.tracing.SubResource.postSub(org.glassfish.jersey.tests.integration.tracing.Message)]
X-Jersey-Tracing-006: RESP-FILTER [ 0.02 / 113.19 ms |  0.01 %] Response summary: 3 filters
X-Jersey-Tracing-007: WI          [89.90 / 204.29 ms | 43.98 %] WriteTo summary: 5 interceptors
X-Jersey-Tracing-008: FINISHED    [ ---- / 204.38 ms |  ---- %] Response status: 200/SUCCESSFUL|OK
Server: Jetty(8.1.8.v20121106)

可以试试看VERBOSE模式：

$ curl -i http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method -H content-type:application/x-jersey-test --data '-=#[LKR]#=-' -H X-Jersey-Tracing-Threshold:VERBOSE -H accept:application/x-jersey-test -X POST

下面是输出：

$ curl -i http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method -H content-type:application/x-jersey-test --data '-=#[LKR]#=-' -H X-Jersey-Tracing-Threshold:VERBOSE -H accept:application/x-jersey-test -X POST
HTTP/1.1 200 OK
Content-Length: 11
Content-Type: application/x-jersey-test
WriterInterceptor39: Mon, 07 May 2018 17:39:00 GMT
WriterInterceptor45: Mon, 07 May 2018 17:39:00 GMT
X-Jersey-Tracing-000: START       [ ---- /  ---- ms |  ---- %] baseUri=[http://localhost:9998/ALL/] requestUri=[http://localhost:9998/ALL/root/sub-resource-locator/sub-resource-method] method=[POST] authScheme=[n/a] accept=[application/x-jersey-test] accept-encoding=n/a accept-charset=n/a accept-language=n/a content-type=[application/x-jersey-test] content-length=[11]
X-Jersey-Tracing-001: START       [ ---- /  0.44 ms |  ---- %] Other request headers: Accept=[application/x-jersey-test] X-Jersey-Tracing-Threshold=[VERBOSE] User-Agent=[curl/7.58.0] Content-Type=[application/x-jersey-test] Content-Length=[11] Host=[localhost:9998]
X-Jersey-Tracing-002: PRE-MATCH   [ 0.00 /  0.77 ms |  0.00 %] Filter by [org.glassfish.jersey.logging.ServerLoggingFilter @19b75b2b #-2147483648]
X-Jersey-Tracing-003: PRE-MATCH   [ 0.00 /  0.81 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.PreMatchingContainerRequestFilter23 @7c71c889 #23]
X-Jersey-Tracing-004: PRE-MATCH   [ 0.01 /  0.83 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.PreMatchingContainerRequestFilter42 @2becfd4c #42]
X-Jersey-Tracing-005: PRE-MATCH   [ 0.11 /  0.85 ms |  0.06 %] PreMatchRequest summary: 3 filters
X-Jersey-Tracing-006: MATCH       [ ---- /  0.87 ms |  ---- %] Matching path [/root/sub-resource-locator/sub-resource-method]
X-Jersey-Tracing-007: MATCH       [ ---- /  0.89 ms |  ---- %] Pattern [/application\.wadl(/)?] is NOT matched
X-Jersey-Tracing-008: MATCH       [ ---- /  0.90 ms |  ---- %] Pattern [/application\.wadl(/.*)?] is NOT matched
X-Jersey-Tracing-009: MATCH       [ ---- /  0.92 ms |  ---- %] Pattern [/async(/)?] is NOT matched
X-Jersey-Tracing-010: MATCH       [ ---- /  0.94 ms |  ---- %] Pattern [/async(/.*)?] is NOT matched
X-Jersey-Tracing-011: MATCH       [ ---- /  0.95 ms |  ---- %] Pattern [/root(/)?] is NOT matched
X-Jersey-Tracing-012: MATCH       [ ---- /  0.98 ms |  ---- %] Pattern [/root(/.*)?] IS selected
X-Jersey-Tracing-013: MATCH       [ ---- /  0.99 ms |  ---- %] Pattern [(/)?] is skipped
X-Jersey-Tracing-014: MATCH       [ ---- /  1.00 ms |  ---- %] Pattern [(/.*)?] is skipped
X-Jersey-Tracing-015: MATCH       [ ---- /  1.02 ms |  ---- %] Matching path [/sub-resource-locator/sub-resource-method]
X-Jersey-Tracing-016: MATCH       [ ---- /  1.04 ms |  ---- %] Pattern [/sub\-resource\-locator\-null(/.*)?] is NOT matched
X-Jersey-Tracing-017: MATCH       [ ---- /  1.05 ms |  ---- %] Pattern [/sub\-resource\-locator(/.*)?] IS selected
X-Jersey-Tracing-018: MATCH       [ ---- /  1.07 ms |  ---- %] Pattern [/sub\-resource\-method(/)?] is skipped
X-Jersey-Tracing-019: MATCH       [ ---- /  1.09 ms |  ---- %] Pattern [/runtime\-exception(/)?] is skipped
X-Jersey-Tracing-020: MATCH       [ ---- /  1.10 ms |  ---- %] Pattern [/mapped\-exception(/)?] is skipped
X-Jersey-Tracing-021: MATCH       [ ---- /  1.11 ms |  ---- %] Pattern [/([^/]+)(/)?] is skipped
X-Jersey-Tracing-022: MATCH       [ ---- /  1.24 ms |  ---- %] Matching path [/sub-resource-method]
X-Jersey-Tracing-023: MATCH       [ ---- /  1.26 ms |  ---- %] Pattern [(/)?] is NOT matched
X-Jersey-Tracing-024: MATCH       [ ---- /  1.28 ms |  ---- %] Pattern [(/.*)?] IS selected
X-Jersey-Tracing-025: MATCH       [ ---- /  1.30 ms |  ---- %] Matching path [/sub-resource-method]
X-Jersey-Tracing-026: MATCH       [ ---- /  1.33 ms |  ---- %] Pattern [/sub\-resource\-method(/)?] IS selected
X-Jersey-Tracing-027: MATCH       [ 0.80 /  1.66 ms |  0.45 %] RequestMatching summary
X-Jersey-Tracing-028: REQ-FILTER  [ 0.00 /  1.72 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.ContainerRequestFilter68 @787d1f9c #68]
X-Jersey-Tracing-029: REQ-FILTER  [ 0.00 /  1.74 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.ContainerRequestFilterNoPriority @4cc8d70d]
X-Jersey-Tracing-030: REQ-FILTER  [ 0.04 /  1.76 ms |  0.03 %] Request summary: 2 filters
X-Jersey-Tracing-031: RI          [ 0.02 /  2.19 ms |  0.01 %] [org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor @5ba1b62e #10] BEFORE context.proceed()
X-Jersey-Tracing-032: RI          [42.13 / 44.35 ms | 23.78 %] [org.glassfish.jersey.tests.integration.tracing.ReaderInterceptor14 @5d2a86c0 #14] BEFORE context.proceed()
X-Jersey-Tracing-033: RI          [ 0.00 / 44.42 ms |  0.00 %] [org.glassfish.jersey.tests.integration.tracing.ReaderInterceptor18 @2c47a053 #18] BEFORE context.proceed()
X-Jersey-Tracing-034: MBR         [ ---- / 44.51 ms |  ---- %] Find MBR for type=[org.glassfish.jersey.tests.integration.tracing.Message] genericType=[org.glassfish.jersey.tests.integration.tracing.Message] mediaType=[application/x-jersey-test] annotations=[]
X-Jersey-Tracing-035: MBR         [ ---- / 44.57 ms |  ---- %] [org.glassfish.jersey.tests.integration.tracing.MessageBodyReaderTestFormat @1fe8f5e8] IS readable
X-Jersey-Tracing-036: MBR         [ ---- / 44.58 ms |  ---- %] [org.glassfish.jersey.tests.integration.tracing.MessageBodyReaderGeneric @2e0ad709] is skipped
X-Jersey-Tracing-037: MBR         [ ---- / 44.60 ms |  ---- %] [org.glassfish.jersey.jaxb.internal.XmlCollectionJaxbProvider$General @4703c998] is skipped
X-Jersey-Tracing-038: MBR         [ ---- / 44.61 ms |  ---- %] [org.glassfish.jersey.jaxb.internal.XmlRootElementJaxbProvider$General @20bb85b4] is skipped
X-Jersey-Tracing-039: MBR         [ ---- / 44.65 ms |  ---- %] [org.glassfish.jersey.jaxb.internal.XmlRootObjectJaxbProvider$General @6c07ad6b] is skipped
X-Jersey-Tracing-040: MBR         [ 0.11 / 44.77 ms |  0.06 %] ReadFrom by [org.glassfish.jersey.tests.integration.tracing.MessageBodyReaderTestFormat @1fe8f5e8]
X-Jersey-Tracing-041: RI          [ 0.00 / 44.80 ms |  0.00 %] [org.glassfish.jersey.tests.integration.tracing.ReaderInterceptor18 @2c47a053 #18] AFTER context.proceed()
X-Jersey-Tracing-042: RI          [43.40 / 88.23 ms | 24.50 %] [org.glassfish.jersey.tests.integration.tracing.ReaderInterceptor14 @5d2a86c0 #14] AFTER context.proceed()
X-Jersey-Tracing-043: RI          [ 0.00 / 88.30 ms |  0.00 %] [org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor @5ba1b62e #10] AFTER context.proceed()
X-Jersey-Tracing-044: RI          [86.50 / 88.32 ms | 48.82 %] ReadFrom summary: 3 interceptors
X-Jersey-Tracing-045: INVOKE      [ 0.01 / 88.37 ms |  0.01 %] Resource [org.glassfish.jersey.tests.integration.tracing.SubResource @2039de7c] method=[public org.glassfish.jersey.tests.integration.tracing.Message org.glassfish.jersey.tests.integration.tracing.SubResource.postSub(org.glassfish.jersey.tests.integration.tracing.Message)]
X-Jersey-Tracing-046: INVOKE      [ ---- / 88.47 ms |  ---- %] Response: [org.glassfish.jersey.message.internal.OutboundJaxrsResponse @653b441f <200/SUCCESSFUL|OK|org.glassfish.jersey.tests.integration.tracing.Message @4275e461>]
X-Jersey-Tracing-047: RESP-FILTER [ 0.00 / 88.58 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.ContainerResponseFilter5001 @341c6ac2 #5001]
X-Jersey-Tracing-048: RESP-FILTER [ 0.00 / 88.60 ms |  0.00 %] Filter by [org.glassfish.jersey.tests.integration.tracing.ContainerResponseFilterNoPriority @38811103]
X-Jersey-Tracing-049: RESP-FILTER [ 0.00 / 88.62 ms |  0.00 %] Filter by [org.glassfish.jersey.logging.ServerLoggingFilter @19b75b2b #-2147483648]
X-Jersey-Tracing-050: RESP-FILTER [ 0.07 / 88.63 ms |  0.04 %] Response summary: 3 filters
X-Jersey-Tracing-051: WI          [ 0.01 / 88.71 ms |  0.00 %] [org.glassfish.jersey.logging.ServerLoggingFilter @19b75b2b #-2147483648] BEFORE context.proceed()
X-Jersey-Tracing-052: WI          [ 0.00 / 88.73 ms |  0.00 %] [org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor @5ba1b62e #10] BEFORE context.proceed()
X-Jersey-Tracing-053: WI          [45.35 / 134.10 ms | 25.59 %] [org.glassfish.jersey.tests.integration.tracing.WriterInterceptor39 @79be91eb #39] BEFORE context.proceed()
X-Jersey-Tracing-054: WI          [ 0.01 / 134.17 ms |  0.01 %] [org.glassfish.jersey.tests.integration.tracing.WriterInterceptor45 @3d1c933 #45] BEFORE context.proceed()
X-Jersey-Tracing-055: WI          [ 0.01 / 134.19 ms |  0.00 %] [org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor @626c569b #4100] BEFORE context.proceed()
X-Jersey-Tracing-056: MBW         [ ---- / 134.29 ms |  ---- %] Find MBW for type=[org.glassfish.jersey.tests.integration.tracing.Message] genericType=[org.glassfish.jersey.tests.integration.tracing.Message] mediaType=[[org.glassfish.jersey.message.internal.AcceptableMediaType @5494e565]] annotations=[@javax.ws.rs.Path(value=sub-resource-method), @javax.ws.rs.POST()]
X-Jersey-Tracing-057: MBW         [ ---- / 134.34 ms |  ---- %] [org.glassfish.jersey.tests.integration.tracing.MessageBodyWriterTestFormat @150fc7a7] IS writeable
X-Jersey-Tracing-058: MBW         [ ---- / 134.37 ms |  ---- %] [org.glassfish.jersey.tests.integration.tracing.MessageBodyWriterGeneric @7ac5b4c] is skipped
X-Jersey-Tracing-059: MBW         [ ---- / 134.39 ms |  ---- %] [org.glassfish.jersey.jaxb.internal.XmlCollectionJaxbProvider$General @4703c998] is skipped
X-Jersey-Tracing-060: MBW         [ ---- / 134.41 ms |  ---- %] [org.glassfish.jersey.jaxb.internal.XmlRootElementJaxbProvider$General @20bb85b4] is skipped
X-Jersey-Tracing-061: MBW         [ 0.08 / 134.51 ms |  0.05 %] WriteTo by [org.glassfish.jersey.tests.integration.tracing.MessageBodyWriterTestFormat @150fc7a7]
X-Jersey-Tracing-062: WI          [ 0.00 / 134.53 ms |  0.00 %] [org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor @626c569b #4100] AFTER context.proceed()
X-Jersey-Tracing-063: WI          [42.42 / 177.00 ms | 23.94 %] [org.glassfish.jersey.tests.integration.tracing.WriterInterceptor45 @3d1c933 #45] AFTER context.proceed()
X-Jersey-Tracing-064: WI          [ 0.00 / 177.08 ms |  0.00 %] [org.glassfish.jersey.tests.integration.tracing.WriterInterceptor39 @79be91eb #39] AFTER context.proceed()
X-Jersey-Tracing-065: WI          [ 0.00 / 177.11 ms |  0.00 %] [org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor @5ba1b62e #10] AFTER context.proceed()
X-Jersey-Tracing-066: WI          [ 0.00 / 177.13 ms |  0.00 %] [org.glassfish.jersey.logging.ServerLoggingFilter @19b75b2b #-2147483648] AFTER context.proceed()
X-Jersey-Tracing-067: WI          [88.46 / 177.15 ms | 49.93 %] WriteTo summary: 5 interceptors
X-Jersey-Tracing-068: FINISHED    [ ---- / 177.18 ms |  ---- %] Response status: 200/SUCCESSFUL|OK
Server: Jetty(8.1.8.v20121106)

以上是对ON_DEMAND模式的tracing功能的一个展示。

阿男的小窝 / Published on May 08, 2018

上一篇 Jersey在Header中添加Tracing信息的方法
下一篇 RESTEasy的容器分析