公司有一个用户行为分析系统，可以记录用户在使用公司产品过程中的一系列操作轨迹，便于分析产品使用情况以便优化产品 UI 界面布局。这套系统有点类似于 Google Analyse（GA），所不同的是，为了让用户把产品用起来，公司会将用户行为与优惠活动联系起来，例如购买产品后一段时间内如果使用时长达到一定标准，就能从销售那里领取小礼品，初衷是为了让用户把产品用起来。可是这个活动一经推出，我这边电话就被打爆了，因为经常有用户感觉自己在用产品了，但是销售给他反馈的时长信息却没有增长。于是实施同事会要求我们去排查问题，可能很多情况下，就是用户没联网、或者防火墙设置的太严格了导致数据上不来、甚至是后台服务挂了导致数据没及时分析……其实 90% 以上的问题和客户端没关系，而是后台在某个环节丢失了数据，但是作为查问题的第一个环节，客户端开发往往会被顶到前线充当 call center 的角色，浪费大量个人时间不说，效率也是极低的。于是自然而然就会想到，能不能做一个分析工具，自动从日志里提出关键数据，做成直观的图表展示给实施人员，可以一眼就能定位出是客户端还是后台的问题，从而达成初步排 (甩) 查 (锅) 的目的？
问题的解决
要能从日志中提取出行为数据（专业术语称为埋点）并根据时间顺序绘制一幅活跃图的根基，是日志中要有相应的记录，巧的是，之前为了排查问题，已经在日志中输出了大量这样的信息：
2020-08-31 10:15:12.531 2248 2564 [1] ########################################### 2020-08-31 10:15:12.531 2248 2564 [2] Service starting ! 2020-08-31 10:15:14.668 2248 2564 [1] collecting OS information... 2020-08-31 10:15:14.949 2248 2564 [1] TimeZone: 480 2020-08-31 10:15:14.949 2248 2564 [1] CountryCode: 86 2020-08-31 10:15:14.949 2248 2564 [1] OSLanugage Name: 1033 2020-08-31 10:15:14.980 2248 2564 [1] Version: 6.1.7601 2020-08-31 10:15:14.980 2248 2564 [1] OSArchitectur: 64-bit 2020-08-31 10:15:14.980 2248 2564 [1] OperatingSystemSKU: 1 2020-08-31 10:15:14.980 2248 2564 [2] Start to init Db. 2020-08-31 10:15:14.980 2248 2564 [2] local device id: 7aaa811b-f720-46b9-bdf3-e6b186cdcc77 2020-08-31 10:15:14.980 2248 2564 [2] sqlite3 database threadsafe = 1 2020-08-31 10:15:15.043 2248 2564 [2] Init Db done. 2020-08-31 10:15:15.043 2248 2564 [2] Start Event Worker. 2020-08-31 10:15:15.043 2248 2564 [2] Start App Worker. 2020-08-31 10:15:15.043 2248 2564 [2] Start Trace Worker. 2020-08-31 10:15:15.043 2248 2564 [2] HB Started. 2020-08-31 10:15:15.043 2248 2564 [1] Local Server Start work done. 2020-08-31 10:15:15.043 2248 3888 [2] Local Server started. 2020-08-31 10:15:15.043 2248 2564 [2] delete files: C:\ProgramData\Glodon\GUX\GCI\\GUX_*.session 2020-08-31 10:15:15.043 2248 2564 [2] start to read strategy from DB 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GMD2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GMJ2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GFYCM2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GAQ2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GJH2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GMJ' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GBS2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GBCB2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GFYC2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GSJ2017' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GFYC' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] add item 'GFYQ' to aggregation list 2020-08-31 10:15:15.043 2248 2564 [2] Read Local App Strategy Done. 2020-08-31 10:15:15.043 2248 2564 [2] Start GMTService done.Version=2.11.0.1777 2020-08-31 10:15:15.043 2248 3724 [2] Adjust Time thread start. 2020-08-31 10:15:15.058 2248 3076 [2] gcm started 2020-08-31 10:15:15.058 2248 3076 [2] Start to Get Strategy. 2020-08-31 10:15:15.058 2248 1748 [2] GUX Online failed, code=4 2020-08-31 10:15:15.089 2248 424 [2] GUX Online succeed. 2020-08-31 10:15:15.121 2248 3076 [1] http get: /v3/server_status?type=102&data_version=2.4, result 200 2020-08-31 10:15:15.121 2248 3076 [4] WinHttpQueryHeaders failed, flag = 0x20000005, errno = 12150 2020-08-31 10:15:15.121 2248 3076 [2] query content length failed, try with transfer-encoding.. 2020-08-31 10:15:15.121 2248 3076 [2] Start to process received message 102 2020-08-31 10:15:15.121 2248 3076 [2] Recv POST strategy. 2020-08-31 10:15:15.121 2248 3076 [2] start post: 1, period: 300 2020-08-31 10:15:15.401 2248 3076 [1] http get: /v3/server_status?type=103&data_version=2.4, result 200 2020-08-31 10:15:15.401 2248 3076 [4] WinHttpQueryHeaders failed, flag = 0x20000005, errno = 12150 2020-08-31 10:15:15.401 2248 3076 [2] query content length failed, try with transfer-encoding.. 2020-08-31 10:15:15.401 2248 3076 [2] Start to process received message 103 2020-08-31 10:15:15.401 2248 3076 [2] Recv TIME strategy. 2020-08-31 10:15:15.401 2248 3076 [2] Time shift: 0 2020-08-31 10:15:15.464 2248 3076 [1] http get: /v3/server_status?type=100&data_version=2.4&md5=ba16886ef2cf522245ad6f0dd20380c958e834ff7bb54d7a2d46fbf416806462, result 200 2020-08-31 10:15:15.464 2248 3076 [4] WinHttpQueryHeaders failed, flag = 0x20000005, errno = 12150 2020-08-31 10:15:15.464 2248 3076 [2] query content length failed, try with transfer-encoding.. 2020-08-31 10:15:15.776 2248 3076 [2] Start to process received message 100 2020-08-31 10:15:15.776 2248 3076 [2] Recv APP strategy. 2020-08-31 10:15:15.776 2248 3076 [2] GrandDog [140]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] CubicostTRB [178]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GTJ2017 [78]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMD2017 [137]: 1, 1, 1 2020-08-31 10:15:15.776 2248 3076 [2] GDraw [180]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GLC [276]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GUX [164]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCCP5 [67]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCCP6 [261]: 1, 1, 0 2020-08-31 10:15:15.776 2248 3076 [2] TME [17]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GWS [25]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] MOZIDIFFER [36]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMJ [40]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GCL2013 [44]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GGJ2013 [45]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] MD_GMA [56]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GDQ2015 [75]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GQI2017 [76]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GJG2015 [77]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMP2016 [80]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] Revit2GFC4GMP [83]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GTJ2017CAD [100]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GYZB2017 [112]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] BIM5D_PC [114]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GFYCM [115]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GBCB [125]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] CubicostTAS [128]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMD [129]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GAQ2017 [131]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GBCB2017 [132]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GBS2017 [133]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GFYC2017 [134]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GFYCM2017 [135]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GMJ2017 [136]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GSJ2017 [138]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GJH2017 [139]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] TeamViewer [142]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] ZPert [148]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GBS [160]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GIR_C [162]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TBQ2017 [163]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GYJC2017 [167]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GSXGZT2016 [177]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TBQD [181]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TTED [182]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TCFD [183]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GSCApp [188]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GFYC [200]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] GDQ2017 [207]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GO [217]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] AppGbmp [218]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GQI2018 [222]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GDS2017 [226]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GLDTCS [228]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TenderGo [231]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GDQ2018 [232]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] SectionManual [233]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] BeamGo [234]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GJG2018 [235]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] RevitViewer [236]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] BIM5D_PC_TEST [237]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] BIM5D_PC_TRIAL [238]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GEC5 [239]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GFYQ [240]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] RoadDesigner [241]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] CECS100G [242]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GBES [243]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] Ceshi [244]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] dpUpdate [245]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GFY4 [246]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GGPT [248]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMA2020 [249]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] JZYK [250]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GVB5 [251]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GHW5 [252]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GUp [253]: 1, 0, 1 2020-08-31 10:15:15.776 2248 3076 [2] BIM_COST [254]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GICP5 [255]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] bim5d_basic [256]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GWH5 [257]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GFY4_2019 [258]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GDD2019 [259]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCCP5_ShanDong_64 [260]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GSC6 [262]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCCP6_WP [263]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GEB6 [264]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GSH6 [265]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GTech2019 [266]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GPC5 [267]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GTJ2021 [268]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GDE2019 [269]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] CubicostTIO [270]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCA5 [271]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GLC5 [272]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GMT5 [273]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GCN5 [274]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GHC5 [275]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GVB6 [277]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GJG2021 [278]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GJG [279]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GAP [280]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GSTP [281]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TRS2021 [283]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] TMEC [284]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] CubicostTMEC [285]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GGF5 [286]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GRE5 [287]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [2] GA_CloudPlugin [310]: 1, 0, 0 2020-08-31 10:15:15.776 2248 3076 [1] Parse App-Id Done. 2020-08-31 10:15:15.869 2248 3076 [2] start to read strategy from DB 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GMD2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GMJ' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GAQ2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GBCB2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GBS2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GFYC2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GFYCM2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GMJ2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GSJ2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GJH2017' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GFYC' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GFYQ' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] add item 'GUp' to aggregation list 2020-08-31 10:15:15.869 2248 3076 [2] Read Local App Strategy Done. 2020-08-31 10:15:15.947 2248 3076 [1] http get: /v3/server_status?type=101&data_version=2.4, result 200 2020-08-31 10:15:15.947 2248 3076 [4] WinHttpQueryHeaders failed, flag = 0x20000005, errno = 12150 2020-08-31 10:15:15.947 2248 3076 [2] query content length failed, try with transfer-encoding.. 2020-08-31 10:15:16.275 2248 3076 [2] Start to process received message 101 2020-08-31 10:15:16.275 2248 3076 [2] Recv KEY strategy. 2020-08-31 10:15:16.275 2248 2984 [1] start posting local information... 2020-08-31 10:15:16.275 2248 2984 [1] User: yunh, Domain: WIN-AS1KN0S7NAJ 2020-08-31 10:15:16.431 2248 2984 [1] User Profile: 2020-08-31 10:15:16.525 2248 2984 [2] load user profile OK 2020-08-31 10:15:16.525 2248 2984 [2] impersonate logged on user OK 2020-08-31 10:15:16.525 2248 2984 [2] revert to self OK 2020-08-31 10:15:16.525 2248 2984 [2] dpi user = yunh, current = 96 2020-08-31 10:15:16.805 2248 2984 [2] dpi infact = 96 2020-08-31 10:15:16.805 2248 2984 [2] dpi scale = 100% 2020-08-31 10:15:16.805 2248 2984 [4] Excute SQL Error: [19] constraint failed SQL=insert into DpiSettingTbl (user, infact, setting, scale) values('yunh','96','96','100') 2020-08-31 10:15:16.805 2248 2984 [3] insert dpi setting for yunh failed, try updating 2020-08-31 10:15:16.868 2248 2984 [1] 2020-08-31 10:15:16.868 2248 2984 [1] environment strings: 2020-08-31 10:15:16.868 2248 2984 [1] ALLUSERSPROFILE=C:\ProgramData 2020-08-31 10:15:16.868 2248 2984 [1] APPDATA=C:\Users\yunh\AppData\Roaming 2020-08-31 10:15:16.868 2248 2984 [1] CommonProgramFiles=C:\Program Files (x86)\Common Files 2020-08-31 10:15:16.868 2248 2984 [1] CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files 2020-08-31 10:15:16.868 2248 2984 [1] CommonProgramW6432=C:\Program Files\Common Files 2020-08-31 10:15:16.868 2248 2984 [1] COMPUTERNAME=WIN-AS1KN0S7NAJ 2020-08-31 10:15:16.868 2248 2984 [1] ComSpec=C:\Windows\system32\cmd.exe 2020-08-31 10:15:16.868 2248 2984 [1] FP_NO_HOST_CHECK=NO 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_COMMON_APPDATA=C:\ProgramData 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_COMMON_DESKTOP=C:\Users\Public\Desktop 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_COMMON_DOCUMENT=C:\Users\Public\Documents 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_COMMON_FILES_32=C:\Program Files (x86)\Common Files 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_COMMON_FILES_64=C:\Program Files\Common Files 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_PROGRAM_FILES_32=C:\Program Files (x86) 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_PROGRAM_FILES_64=C:\Program Files 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_SYSTEM_32=C:\Windows\SysWOW64 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_SYSTEM_64=C:\Windows\system32 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_SYSTEM_DRIVE=C: 2020-08-31 10:15:16.868 2248 2984 [1] GLODON_WINDOWS_DIR=C:\Windows 2020-08-31 10:15:16.868 2248 2984 [1] HOMEDRIVE=C: 2020-08-31 10:15:16.868 2248 2984 [1] HOMEPATH=\Users\yunh 2020-08-31 10:15:16.868 2248 2984 [1] LOCALAPPDATA=C:\Users\yunh\AppData\Local 2020-08-31 10:15:16.868 2248 2984 [1] LOGONSERVER=\\WIN-AS1KN0S7NAJ 2020-08-31 10:15:16.868 2248 2984 [1] NUMBER_OF_PROCESSORS=1 2020-08-31 10:15:16.868 2248 2984 [1] OS=Windows_NT 2020-08-31 10:15:16.868 2248 2984 [1] Path=C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\ 2020-08-31 10:15:16.868 2248 2984 [1] PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC 2020-08-31 10:15:16.868 2248 2984 [1] PROCESSOR_ARCHITECTURE=AMD64 2020-08-31 10:15:16.868 2248 2984 [1] PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 60 Stepping 3, GenuineIntel 2020-08-31 10:15:16.868 2248 2984 [1] PROCESSOR_LEVEL=6 2020-08-31 10:15:16.868 2248 2984 [1] PROCESSOR_REVISION=3c03 2020-08-31 10:15:16.868 2248 2984 [1] ProgramData=C:\ProgramData 2020-08-31 10:15:16.868 2248 2984 [1] ProgramFiles=C:\Program Files (x86) 2020-08-31 10:15:16.868 2248 2984 [1] ProgramFiles(x86)=C:\Program Files (x86) 2020-08-31 10:15:16.868 2248 2984 [1] ProgramW6432=C:\Program Files 2020-08-31 10:15:16.868 2248 2984 [1] PSModulePath=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\ 2020-08-31 10:15:16.868 2248 2984 [1] PUBLIC=C:\Users\Public 2020-08-31 10:15:16.868 2248 2984 [1] SystemDrive=C: 2020-08-31 10:15:16.868 2248 2984 [1] SystemRoot=C:\Windows 2020-08-31 10:15:16.868 2248 2984 [1] TEMP=C:\Users\yunh\AppData\Local\Temp 2020-08-31 10:15:16.868 2248 2984 [1] TMP=C:\Users\yunh\AppData\Local\Temp 2020-08-31 10:15:16.868 2248 2984 [1] USERDOMAIN=WIN-AS1KN0S7NAJ 2020-08-31 10:15:16.868 2248 2984 [1] USERNAME=yunh 2020-08-31 10:15:16.868 2248 2984 [1] USERPROFILE=C:\Users\yunh 2020-08-31 10:15:16.868 2248 2984 [1] windir=C:\Windows 2020-08-31 10:15:16.868 2248 2984 [1] windows_tracing_flags=3 2020-08-31 10:15:16.868 2248 2984 [1] windows_tracing_logfile=C:\BVTBin\Tests\installpackage\csilogfile.log 2020-08-31 10:15:16.868 2248 2984 [1] 2020-08-31 10:15:21.673 2248 2984 [2] first got hwid: {C4F752B9-EF31-580A-B75C-67E300000000} 2020-08-31 10:15:21.673 2248 2984 [2] first got ssid: 2020-08-31 10:15:21.673 2248 2984 [1] local info:{ "metrics": { "os": "Windows", "os_version": "7", "os_version1": "6.1.7601", "os_edition": "Ultimate Edition", "dev_type": "PC", "resolution": "1920x1080", "sysbits": "64", "cpu_sum": "Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz 3.60GHz", "total_mem": "2048MB", "language": "English (United States)", "pctype": "unknown", "language_id": "1033", "timezone": "8", "dpiscale": "100" }, "mem": { "total_mem": "2048MB" }, "videocards": [ { "name": "VMware SVGA 3D", "manufacturer": "VMware, Inc.", "chipset": "VMware Virtual SVGA 3D Graphics Adapter", "dac_type": "n\/a", "memory": "1024MB", "inuse": "1", "pixelbits": "32", "monitor_count": "1", "driverversion": "8.15.1.33", "driverdate": "20151016000000.000000-000", "pnpdeviceid": "PCI\\VEN_15AD&DEV_0405&SUBSYS_040515AD&REV_00\\3&2B8E0B4B&0&78", "caption": "VMware SVGA 3D", "frequency": "60Hz", "resolution": "1920x1080" } ], "cpu": { "name": "Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz", "manufacturer": "GenuineIntel", "physicalcores": "1", "logicalcores": "1", "frequency": "3.60GHz", "address_width": "64", "voltage": "33" }, "baseboard": { "manufacturer": "Intel Corporation", "product": "440BX Desktop Reference Platform", "sn": "None" }, "dpisetting": [ { "user": "yunh", "infact": "96", "setting": "96", "scale": "100" } ], "msg_type": "7", "app_name": "GUX", "app_version": "2.11.0.1777", "device_id": "7aaa811b-f720-46b9-bdf3-e6b186cdcc77", "mt_devid": "{C4F752B9-EF31-580A-B75C-67E300000000}", "ssid": "", "timestamp": "1598840121673", "sessionid": "", "extra": "" } 2020-08-31 10:15:21.673 2248 2984 [2] Read device info succeed. 2020-08-31 10:15:21.673 2248 2984 [2] local hardware changed, prepare to post system information 2020-08-31 10:15:21.673 2248 2984 [2] first got ssid: 2020-08-31 10:15:21.766 2248 2984 [1] http post: /v3/do, result 200 2020-08-31 10:15:21.766 2248 2984 [1] 6 : finish 2020-08-31 10:15:21.766 2248 2984 [2] Post local information succeed.. 2020-08-31 10:15:21.766 2248 2984 [1] collectLocalInfoData end... 2020-08-31 10:15:44.650 2248 3888 [2] local client accepted. 2020-08-31 10:15:44.681 2248 2936 [2] Send sync msg to Client, socketNo=1, len=46 2020-08-31 10:15:44.681 2248 2936 [2] GDraw start, appid = B84c955afdfe63ae1acf0e1a45f6dcc9e4fb64a3, inst = 1473 2020-08-31 10:15:44.697 2248 3800 [2] add event 3 (1) 2020-08-31 10:15:44.697 2248 3360 [4] Excute SQL Error: [21] library routine called out of sequence SQL=insert into B84c955afdfe63ae1acf0e1a45f6dcc9e4fb64a3(type, key , count , data, timestamp ) values('5','启动','1','{"dognum":"","fname":"Æô¶¯","fngroup":"VisDraw","gid":"","pcode":"-110000","query":{},"sessionid":"3680"} ','1598840144697') 2020-08-31 10:15:44.697 2248 3360 [1] add action GDraw.启动 (0) 2020-08-31 10:15:44.697 2248 3360 [2] create action table B84c955afdfe63ae1acf0e1a45f6dcc9e4fb64a3 (1). 2020-08-31 10:15:44.712 2248 3360 [2] insert 1 record into db by transaction elapsed 10 ms 2020-08-31 10:15:44.837 2248 3360 [1] add action GDraw.新建文件 (1) 2020-08-31 10:15:44.837 2248 3360 [2] insert 1 record into db by transaction elapsed 1 ms 2020-08-31 10:15:45.071 2248 3076 [2] Save Timer Expired.Start to Save Aggregation Data. 2020-08-31 10:15:48.254 2248 3360 [1] add action GDraw.添加弧 (1) 2020-08-31 10:15:48.254 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:15:53.683 2248 3360 [1] add action GDraw.添加长方形 (1) 2020-08-31 10:15:53.683 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:15:57.349 2248 3360 [1] add action GDraw.添加圆 (1) 2020-08-31 10:15:57.349 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:16:01.389 2248 1992 [2] GLC heart beat timeout, appid = B21170b9e920c9c0fb57374ee21d0b71af1adf3d, inst = 2 2020-08-31 10:16:01.389 2248 1992 [2] GDraw heart beat timeout, appid = Bb3e5dfebfa0f02d987a93865bc9aed3e81dee09, inst = 3 2020-08-31 10:16:01.389 2248 3800 [2] add event 4 (1) 2020-08-31 10:16:01.389 2248 3800 [2] add event 4 (1) 2020-08-31 10:16:03.854 2248 3360 [1] add action GDraw.添加圆 (1) 2020-08-31 10:16:03.869 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:10.843 2248 3360 [1] add action GDraw.添加椭圆 (1) 2020-08-31 10:16:10.843 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:14.290 2248 3360 [1] add action GDraw.添加多边形 (1) 2020-08-31 10:16:14.290 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:16:19.251 2248 3360 [1] add action GDraw.添加文本 (1) 2020-08-31 10:16:19.251 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:24.274 2248 3360 [1] add action GDraw.添加直线 (1) 2020-08-31 10:16:24.274 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:37.363 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:16:37.378 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:37.378 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:16:37.378 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:16:37.394 2248 3360 [2] insert 2 record into db by transaction elapsed 17 ms 2020-08-31 10:16:41.325 2248 3360 [1] add action GDraw.置底椭圆 (1) 2020-08-31 10:16:41.325 2248 3360 [1] add action GDraw.置底文本 (1) 2020-08-31 10:16:41.325 2248 3360 [1] add action GDraw.置底直线 (1) 2020-08-31 10:16:41.341 2248 3360 [2] insert 3 record into db by transaction elapsed 3 ms 2020-08-31 10:16:45.943 2248 3360 [1] add action GDraw.移动椭圆 (1) 2020-08-31 10:16:45.943 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:16:49.390 2248 3360 [1] add action GDraw.删除圆 (1) 2020-08-31 10:16:49.390 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:16:52.963 2248 3360 [1] add action GDraw.删除圆 (1) 2020-08-31 10:16:52.978 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:16:55.162 2248 3360 [1] add action GDraw.粘贴圆 (1) 2020-08-31 10:16:55.162 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:16:59.873 2248 3360 [1] add action GDraw.调整圆 (1) 2020-08-31 10:16:59.873 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:17:04.475 2248 3360 [1] add action GDraw.调整长方形 (1) 2020-08-31 10:17:04.475 2248 3360 [2] insert 1 record into db by transaction elapsed 4 ms 2020-08-31 10:17:07.798 2248 3360 [1] add action GDraw.调整多边形 (1) 2020-08-31 10:17:07.798 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:17:11.511 2248 3360 [1] add action GDraw.调整弧 (1) 2020-08-31 10:17:11.511 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:17:16.019 2248 3360 [1] add action GDraw.调整直线 (1) 2020-08-31 10:17:16.035 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:17:44.973 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:17:44.973 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:17:44.973 2248 3360 [1] add action GDraw.设置文本 (1) 2020-08-31 10:17:44.989 2248 3360 [2] insert 3 record into db by transaction elapsed 7 ms 2020-08-31 10:17:48.140 2248 3360 [1] add action GDraw.调整文本 (1) 2020-08-31 10:17:48.156 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:17:55.924 2248 3360 [1] add action GDraw.删除文本 (1) 2020-08-31 10:17:55.924 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:18:07.188 2248 3360 [1] add action GDraw.保存文件 (1) 2020-08-31 10:18:07.188 2248 3360 [2] insert 1 record into db by transaction elapsed 4 ms 2020-08-31 10:18:08.326 2248 3360 [1] add action GDraw.关闭文件 (1) 2020-08-31 10:18:08.326 2248 3360 [2] insert 1 record into db by transaction elapsed 2 ms 2020-08-31 10:18:08.576 2248 3888 [4] local client disconnected: End of file 2020-08-31 10:18:08.576 2248 2936 [2] GDraw stop, appid = B84c955afdfe63ae1acf0e1a45f6dcc9e4fb64a3, inst = 1473 2020-08-31 10:18:08.576 2248 3360 [1] add action GDraw.退出 (1) 2020-08-31 10:18:08.576 2248 3360 [2] insert 1 record into db by transaction elapsed 3 ms 2020-08-31 10:18:08.576 2248 3800 [2] add event 4 (1) ……