Tweet
Tweet

Slide 1

Slide 1 text

To Connect the Dogs @ColinBendell CTO Office, Cloudinary Server-Timing Dots DATA

Slide 2

Slide 2 text

@ColinBendell

Slide 3

Slide 3 text

No content

Slide 4

Slide 4 text

No content

Slide 5

Slide 5 text

Today •Psychology of the User XP •Connecting User & Service Telemetry •Efficient Multi-Variant Analysis

Slide 6

Slide 6 text

How To: •impress your Boss •impress your Co-Workers •impress your Mom Put Another Way…

Slide 7

Slide 7 text

No content

Slide 8

Slide 8 text

No content

Slide 9

Slide 9 text

The User Experience

Slide 10

Slide 10 text

No content

Slide 11

Slide 11 text

"I just want to share my photos from last night" "I want to buy a birthday present for mom" "I want to check the news"

Slide 12

Slide 12 text

Sometimes experience doesn't match expectations

Slide 13

Slide 13 text

#WebPerf: Correlating Performance and Conversion

Slide 14

Slide 14 text

No content

Slide 15

Slide 15 text

No content

Slide 16

Slide 16 text

??

Slide 17

Slide 17 text

“We develop in the Zoo, But release in the Jungle” -Melanie Cey

Slide 18

Slide 18 text

What Happened? •Blue-green / MV test? •Service disruption? •Data Inconsistency? •Poor UX? •MiTM?

Slide 19

Slide 19 text

Our EcoSystem of the Telemetry Data

Slide 20

Slide 20 text

No content

Slide 21

Slide 21 text

88.225.187.184 GET /cornfield.gif 200 20482 41110 $ cat access.log|grep cornfield.gif ¯\_()_/¯

Slide 22

Slide 22 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User #!"#

Slide 23

Slide 23 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User #!"# User #$"%

Slide 24

Slide 24 text

88.225.187.184 GET /cornfield.gif 200 20482 41110 $ cat access.log|grep cornfield.gif ¯\_()_/¯

Slide 25

Slide 25 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User ! ! ! ! ! ! ! ! !

Slide 26

Slide 26 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User !

Slide 27

Slide 27 text

Oct 13 17:52:20 syslogd[49]: ASL Sender Statistics Oct 13 17:52:20 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 17:52:20 --- last message repeated 1 time --- Oct 13 17:52:20 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70139): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/Frameworks/IDEKit.fra Oct 13 17:52:20 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70139): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/SharedFrameworks/LLDB Oct 13 17:52:59 idea[70147]: allVms required 1.8*,1.8+ Oct 13 17:52:59 idea[70147]: Value of IDEA_VM_OPTIONS is (null) Oct 13 17:52:59 idea[70147]: Processing VMOptions file at /Users/colin/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/182.4505.22/IntelliJ IDEA.app.vmoptions Oct 13 17:52:59 idea[70147]: Done Oct 13 17:53:01 idea[70147]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 17:53:02 com.apple.xpc.launchd[1] (com.apple.quicklook[70271]): Endpoint has been activated through legacy launch(3) APIs. Please switch to XPC or bootstrap_check_in(): com.apple.quicklook Oct 13 17:53:10 xpcproxy[70325]: libcoreservices: _dirhelper_userdir: 529: bootstrap_look_up returned (ipc/send) invalid destination port Oct 13 17:56:42 com.apple.xpc.launchd[1] (com.apple.appkit.xpc.openAndSavePanelService[69418]): Service did not exit 5 seconds after SIGTERM. Sending SIGKILL. Oct 13 18:00:33 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.user.501): Service "com.apple.xpc.launchd.unmanaged.loginwindow.109" tried to register for endpoint "com.apple.tsm.uiserver" already registered by Oct 13 18:27:56 --- last message repeated 1 time --- Oct 13 18:27:56 syslogd[49]: ASL Sender Statistics Oct 13 18:28:01 iTunesCacheExtension[70380]: objc[70380]: Class ITNSImage is implemented in both /System/Library/Frameworks/iTunesLibrary.framework/Versions/A/iTunesLibrary (0x7fff876d7568) and /Applications/iTunes.app Oct 13 18:28:01 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:28:02 --- last message repeated 1 time --- Oct 13 18:28:02 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70379): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/Frameworks/IDEKit.fra Oct 13 18:28:02 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70379): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/SharedFrameworks/LLDB Oct 13 18:30:24 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.user.501): Service "com.apple.xpc.launchd.unmanaged.loginwindow.109" tried to register for endpoint "com.apple.tsm.uiserver" already registered by Oct 13 18:31:44 --- last message repeated 1 time --- Oct 13 18:32:04 com.apple.xpc.launchd[1] (com.apple.eospreflightagent): Service only ran for 521 seconds. Pushing respawn out by 379 seconds. Oct 13 18:32:04 xpcproxy[70406]: libcoreservices: _dirhelper_userdir: 529: bootstrap_look_up returned (ipc/send) invalid destination port Oct 13 18:32:12 xpcproxy[70420]: libcoreservices: _dirhelper_userdir: 529: bootstrap_look_up returned (ipc/send) invalid destination port Oct 13 18:32:13 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:32:38 System Preferences[70426]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:32:38 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:32:49 com.apple.preferences.sharing.remoteservice[70435]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:32:54 com.apple.xpc.launchd[1] (com.apple.WebKit.Networking.E25DA39A-B766-4939-9E11-5B36F36493A7[70409]): Service exited with abnormal code: 1 Oct 13 18:33:02 xpcproxy[70439]: libcoreservices: _dirhelper_userdir: 529: bootstrap_look_up returned (ipc/send) invalid destination port Oct 13 18:34:46 ContainerMetadataExtractor[70445]: objc[70445]: Class BRMangledID is implemented in both /System/Library/PrivateFrameworks/CloudDocs.framework/Versions/A/CloudDocs (0x7fff88192dd8) and /System/Library/P Oct 13 18:35:10 com.apple.xpc.launchd[1] (com.apple.quicklook[70448]): Endpoint has been activated through legacy launch(3) APIs. Please switch to XPC or bootstrap_check_in(): com.apple.quicklook Oct 13 18:35:15 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:35:15 Notes[70463]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:38:03 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:38:04 syslogd[49]: ASL Sender Statistics Oct 13 18:38:03 iTunesCacheExtension[70472]: objc[70472]: Class ITNSImage is implemented in both /System/Library/Frameworks/iTunesLibrary.framework/Versions/A/iTunesLibrary (0x7fff876d7568) and /Applications/iTunes.app Oct 13 18:38:03 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:38:04 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70468): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/Frameworks/IDEKit.fra Oct 13 18:38:04 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70468): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/SharedFrameworks/LLDB Oct 13 18:42:23 CharacterPalette[70475]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:42:26 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:44:07 CharacterPalette[70478]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:44:33 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:45:16 OSDUIHelper[70480]: DEPRECATED USE in libdispatch client: dispatch source activated with no event handler set; set a breakpoint on _dispatch_bug_deprecated to debug Oct 13 18:47:51 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.user.501): Service "com.apple.xpc.launchd.unmanaged.loginwindow.109" tried to register for endpoint "com.apple.tsm.uiserver" already registered by Oct 13 18:48:04 --- last message repeated 1 time --- Oct 13 18:48:04 syslogd[49]: ASL Sender Statistics Oct 13 18:48:05 iTunesCacheExtension[70485]: objc[70485]: Class ITNSImage is implemented in both /System/Library/Frameworks/iTunesLibrary.framework/Versions/A/iTunesLibrary (0x7fff876d7568) and /Applications/iTunes.app Oct 13 18:48:05 com.apple.xpc.launchd[1] (com.apple.imfoundation.IMRemoteURLConnectionAgent): Unknown key for integer: _DirtyJetsamMemoryLimit Oct 13 18:48:05 --- last message repeated 1 time --- Oct 13 18:48:05 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70487): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/Frameworks/IDEKit.fra Oct 13 18:48:05 com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.pid.IDECacheDeleteAppExtension.70487): Path not allowed in target domain: type = pid, path = /Applications/Xcode.app/Contents/SharedFrameworks/LLDB Oct 13 19:00:38 syslogd[49]: ASL Sender Statistics

Slide 28

Slide 28 text

So you've got a data lake…

Slide 29

Slide 29 text

Headwinds & Considerations • Performance v. Product • Log ownership • COGS of Tracing • Hawthorn Effect • GDPR

Slide 30

Slide 30 text

• Share identifiers • Compare both sides (Server:Server, User:Server) • Collect User telemetry (eg: boomerang, LUX, mPulse) • Server-Timing is more than timing

Slide 31

Slide 31 text

Strategy 1 Annotate your logging with a shared identifier

Slide 32

Slide 32 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage! ! ! ! ! ! ! Option 1: Identifier Inheritance

Slide 33

Slide 33 text

88.225.187.184 GET /corn.gif 200 20482 41110 ID_1234.56 $ cat access.log|grep corn.gif $ cat db-access.log|grep ID1234.56 ID_1234.56 "SELECT URL FROM FUNNY_GIFS …" 2043

Slide 34

Slide 34 text

Option 2: Late Annotation with Server-Timing

Slide 35

Slide 35 text

Server-Timing: cloudinary, dur="10", desc="Bicycle Cat" name description duration

Slide 36

Slide 36 text

GET /api/db/product HTTP/1.1 Host: example.com HTTP/1.1 200 OK Server-Timing: id, desc="sub-def456.78" Server-Timing: db, dur=2043 Request Response

Slide 37

Slide 37 text

{ ip: "88.225.187.184", url: "/corn.gif", status: 200, size:" 20482", duration: 41110, id: "ID_1234.56", db: [{ id: "sub-def456.78", dur: 2043 }] } $ cat access.log|grep corn.gif

Slide 38

Slide 38 text

Strategy 1: Shared Identifier • Connect logging • Option 1: Inherit a shared ID • Option 2: Collect late with Server-"Timing" API

Slide 39

Slide 39 text

Strategy 2 Use Server-"Timing" to pass essential details upstream

Slide 40

Slide 40 text

GET /cms/sale.html HTTP/1.1 Host: example.com HTTP/1.1 200 OK Server-Timing: db-id, desc="sub-def456.78" Server-Timing: db, dur=2043 Request Response Server-Timing: cms-id, desc="abc123.45" Server-Timing: cms, dur=41110 Stash & Remove Add & Annotate

Slide 41

Slide 41 text

GET /cms/sale.html HTTP/1.1 Host: example.com HTTP/1.1 200 OK Server-Timing: db-reqid, desc="sub-def456.78" Server-Timing: db, dur=2043 Request Response Server-Timing: cms-reqid, desc="abc123.45" Server-Timing: cms, dur=41110 Server-Timing: error, desc="personalisation timeout" Server-Timing: key, desc="shoes123, shirts456"

Slide 42

Slide 42 text

44 Server-Timing is more than Timing

Slide 43

Slide 43 text

Strategy 2 Annotate Essentials • clock-time vs effort-time • Normalize early; add useful information early • Eg: Primary Keys, Non-Critical Errors

Slide 44

Slide 44 text

Strategy 3 Compare both sides

Slide 45

Slide 45 text

No content

Slide 46

Slide 46 text

Front End Server DB: Prod lookup Front End Server AuthGate CMS DAM Radius Storage DB: Geo-Price DB: inventory DB: Prod lookup Each Service Has a Hidden Cost: Infrastructure

Slide 47

Slide 47 text

Front End Server DB: Prod lookup 41,115ms 41,110ms 22,083 ms 2043 ms

Slide 48

Slide 48 text

{ ip: "88.225.187.184", url: "/corn.gif", status: 200, size:" 20482", duration: 41110, id: "ID_1234.56", db: [{ id: "sub-def456.78", dur: 2043, total: 22033, }] } $ cat access.log|grep corn.gif

Slide 49

Slide 49 text

Strategy 3 • The network is not zero • Use Server-Timing to measure time dilation • Compare server:server

Slide 50

Slide 50 text

Strategy 4 End User Telemetry

Slide 51

Slide 51 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User

Slide 52

Slide 52 text

https://www.w3.org/wiki/Web_Performance/Publications

Slide 53

Slide 53 text

No content

Slide 54

Slide 54 text

function logData() { navigator.sendBeacon("/log", data); }

Slide 55

Slide 55 text

No content

Slide 56

Slide 56 text

Navigation Timing API

Slide 57

Slide 57 text

window.performance

Slide 58

Slide 58 text

{ "timeOrigin": 1528900579651.6672, "timing": { "navigationStart": 1528900579651, "unloadEventStart": 0, "unloadEventEnd": 0, "redirectStart": 0, "redirectEnd": 0, "fetchStart": 1528900583010, "domainLookupStart": 1528900579730, "domainLookupEnd": 1528900579730, "connectStart": 1528900579730, "connectEnd": 1528900579761, "secureConnectionStart": 1528900579733, "requestStart": 1528900579761, "responseStart": 1528900582922, "responseEnd": 1528900583010, "domLoading": 1528900583014, "domInteractive": 1528900583849, "domContentLoadedEventStart": 1528900583849, "domContentLoadedEventEnd": 1528900583876, "domComplete": 1528900585616, "loadEventStart": 1528900585617, "loadEventEnd": 1528900585856 }, "navigation": {"type": 0, "redirectCount": 0 } }

Slide 59

Slide 59 text

No content

Slide 60

Slide 60 text

No content

Slide 61

Slide 61 text

window.performance.getEntries()[0]

Slide 62

Slide 62 text

{ "name": "https://ajax.googleapis.com/ajax/libs/jquery/1.11.2/jquery.min.js", "entryType": "resource", "startTime": 928.70000000039, "duration": 425.8000000008906, "initiatorType": "script", "nextHopProtocol": "h2", "workerStart": 0, "redirectStart": 0, "redirectEnd": 0, "fetchStart": 928.70000000039, "domainLookupStart": 937.4000000025262, "domainLookupEnd": 945.9000000024389, "connectStart": 945.9000000024389, "connectEnd": 967.5999999999476, "secureConnectionStart": 946.2000000021362, "requestStart": 949.5999999999185, "responseStart": 970.9000000002561, "responseEnd": 1354.5000000012806, "transferSize": 33798, "encodedBodySize": 33495, "decodedBodySize": 95931, "serverTiming": [] }

Slide 63

Slide 63 text

let url = “https://bendell.ca/logo.png”; let me = performance.getEntriesByName(url)[0]; let timings = { loadTime: me.duration, dns: me.domainLookupEnd - me.domainLookupStart, tcp: me.connectEnd - me.connectStart, waiting: me.responseStart - me.requestStart, fetch: me.responseEnd - me.responseStart }

Slide 64

Slide 64 text

No content

Slide 65

Slide 65 text

GET /resource HTTP/1.1 Host: example.com HTTP/1.1 200 OK Server-Timing: cdn, dur=130, desc="MISS" Server-Timing: cloudinary, dur="10", desc="thumbnail"

Slide 66

Slide 66 text

{ let url = 'https://example.com/resource.jpg’; let severEntries[] = window.performance.getEntriesByName(url) .filter((name) => name === "server"); }

Slide 67

Slide 67 text

GET /resource HTTP/1.1 Host: example.com HTTP/1.1 200 OK Server-Timing: cdn, dur=130, desc="MISS" Server-Timing: cloudinary, dur="10", desc="thumbnail" Server-Timing: is-cellular, desc="true" Server-Timing: rtt, dur=150

Slide 68

Slide 68 text

Strategy 4 •Use BeaconAPI to send user experience logs back •NavTiming, UserTiming APIs •Server-Timing is accessible in JavaScript

Slide 69

Slide 69 text

Strategy 5 Parse & Simplify

Slide 70

Slide 70 text

Front End Server AuthGate Radius CMS DB: Prod lookup DB: inventory DB: Geo- Price DAM Storage User ! ! ! ! ! ! ! ! ! !

Slide 71

Slide 71 text

Import Log Ship Airflow Kinesis Normalize Spark Annotation Sanitization Store Snowflake (snowpipe) Rollups Analyze BI (Qliksense) R Jupyter

Slide 72

Slide 72 text

Take Action • Share identifiers • Compare both sides (Server:Server, User:Server) • Collect User telemetry (eg: boomerang, LUX, mPulse) • Server-Timing is more than timing

Slide 73

Slide 73 text

Thank-You!

Slide 74

Slide 74 text

@ColinBendell