为什么首页 PV 事件会重复上报?

首先来讲讲第一个bug,QA说,每次进入页面,都会对lark_website_mainpage_view事件上报两次,如下图所示:
alt text

每次刷新页面,的确是会看到两次该事件的上报。
其实这块儿我并不是很确定是否是组里其他更有权威的同事的故意设计如此,但是我看到两次埋点事件的上报参数是有一些区别的,后一次的lark_website_mainpage_view事件的上报多了两个参数,分别是page_title和url_from,一个应该是页面的标题,一个应该是从哪儿跳转到当前页面的?不过我感觉不重要,重要的是,这里好像的确是一个bug。

排查

由于对官网页面的埋点方案不是很了解,于是跟同事们问了一下,这个埋点最终是通过 /list 请求去上报数据的,于是我就去network里过滤出了 list 请求去看,果然让我发现了,有两个lark_website_mainpage_view事件上报出现在了同一个list请求里,如下图:
alt text

这块儿虽然确实能看到两个相同的初始化事件埋点上报,但是我很疑惑,怎么这两个事件甚至还有其他的事件一起参杂在同一个请求里,我去翻后来的其他 list 请求中,都是一次请求上报一个事件,唯独页面第一个list请求是一次一堆事件上报。

为了弄清楚这一点,我发觉我必须要知道是哪个脚本在调用这个 list 接口。

因为我有埋点工具的组件源代码在本地,于是询问了一下大模型,这个埋点工具是怎么上报埋点的。

大模型很快就给我定位到了工具的关键信息上传:

//传入事件名和参数
window.collectEvent(eventName, params);

这就意味着埋点工具并没有直接去调用list请求,而是通过调用window上挂载的一个函数上报的事件,显然,collectEvent函数的具体实现我估计本地源码上找不到,应该是我们组内的发版平台给页面注入的脚本里实现了这个collectEvent。

既然 collectEvent 被挂载在 window 上,最直接的办法就是先去浏览器 Console 中查看!在浏览器的控制台输入:

window.collectEvent

结果控制台跳出来一段不完整的代码,点一下就跳转到了sources栏的一个名为collect.js的文件里,在这个文件里搜 collectEvent 并不能搜索到结果,因为我看这个文件所有的变量都是单个字母,似乎是被混淆过的文件,而且这个文件中应该是需要对window的collectEvent函数进行实现,那么这个文件有可能是通过这种代码去做的:

const name = window.xxx
window[name] = function(eventName, params) {...}

这种做法等价于:

window.collectEvent = function(eventName, params) {...}

这样或许能解释为什么我在这个文件中搜索不到 collectEvent

我没有死心,直接去 doc 文件看看能不能搜到,果然让我搜到了21条记录。

第一条匹配记录就收获惊人:

(function(win, exportObj) {
    win["LogAnalyticsObject"] = exportObj;
    if (!win[exportObj]) {
        var _collect = function _collect() {
            _collect.q.push(arguments)
        };
        _collect.q = _collect.q || [];
        win[exportObj] = _collect
    }
    win[exportObj].l = +new Date
}
)(window, "collectEvent");

仔细一看这个函数做了啥,发现看来的确是把collectEvent函数名通过键值对的方式存到了全局对象里,这样其他所有的脚本都会通过 LogAnalyticsObject 的键去拿到函数名,当这个函数还没有被注入时,这里是给它加了一个占位函数,能够让业务代码在页面加载好上报埋点的函数之前调用 collectEvent也能收集好埋点状态,就比如页面刚加载时的初始埋点事件,这也印证了我们开头的疑问,为什么页面刚加载时需要上报的一些事件都是一堆放在一个请求里上报的,就是因为刚加载时真正的上报脚本还没有加载好,调用的是占位上报函数。

继续往下匹配 collectEvent函数的调用,果然有所发现:

var delayTime = 0;

setTimeout(function() {
    // 发起 Tea 公共参数脚本的异步加载。_loadScript 调用后会立即返回,
    // 不会等待外部脚本下载完成,因此下面的首页 PV 代码会继续执行。
    _loadScript(
        "",
        "https://lf-package-sg.larksuitecdn.com/obj/unpkg-va/bdeefe/ug-tea-common-params/1.0.36/dist/index.min.js",
        function() {
            // 外部脚本加载并执行完成后,才会进入这个 onload 回调初始化 Tea。
            var _window$__globalVars_, _window$__globalVars_2;

            window.teaCommonParams.configTea(
                1660, // Tea 应用 ID
                "sg", // 数据上报区域
                {
                    cross_subdomain: true,
                    cookie_expire: 12 * 30 * 24 * 60 * 60 * 1000,
                    channel_domain: "https://mcs-bd-sg.larksuite.com",
                    autotrack: { custom: "tea" }
                },
                {
                    url_path: window.location.pathname,
                    url: window.location.href,
                    is_login: (_window$__globalVars_ = window.__globalVars__) === null ||
                        _window$__globalVars_ === void 0 ? void 0 : _window$__globalVars_.loginStatus,
                    lark_user_id: (_window$__globalVars_2 = window.__globalVars__) === null ||
                        _window$__globalVars_2 === void 0 ? void 0 : _window$__globalVars_2.userDigest
                },
                {
                    app_language: window.__lang__,
                    _staging_flag: window.__globalVars__.env == "boe" ? 1 : 0
                }
            );
        }
    );

    // 这里不会等待上面的 Tea 脚本加载完成,而是立即执行首页 PV 上报。
    (function() {
        // 将 ?from=xxx 等 URL 查询参数转换成对象。
        function _getParamsObjFromSearch(search) {
            if (!search) return {};

            var arr = search.slice(1).split("&");
            var obj = {};

            arr.forEach(function(item) {
                var keyValue = item.split("=");
                if (keyValue[1]) {
                    obj[keyValue[0]] = decodeURIComponent(keyValue[1]);
                }
            });
            return obj;
        }

        var searchObj = _getParamsObjFromSearch(location.search);
        var url_from = searchObj["from"] || "";

        // 此时真实 Tea SDK 很可能尚未就绪,这次调用会先进入 collectEvent.q。
        window.collectEvent("lark_website_mainpage_view", {
            page_title: document.title,
            url_from: url_from
        });
    })();
}, delayTime);

很明显,这里就是上报 lark_website_mainpage_view 事件的代码位置之一,而且是多两个参数的那个版本。

继续往下搜索 collectEvent 又发现一个立即执行函数内部有一个函数的定义:

function sendTeaEvent(eventName, params) {
    if (!window.collectEvent) {
        return;
    }
    window.collectEvent(eventName, params);
}

如果存在某个代码位置调用了这个函数,并且传入的事件名为 lark_website_mainpage_view ,那么两个事件的触发位置也就都找到了。

不出所料,就在当前这个立即函数内部有一段函数的调用:

sendTeaEvent('lark_website_mainpage_view');

这一下就明白为什么每次进入页面会有两次这个事件的上报了。(突然想到直接在sources里搜索 lark_website_mainpage_view岂不是更快找到?哈哈😂)

既然这两次事件之前是在一个请求里发送的,说明这两个事件真正执行的时候,collectEvent 函数还是占位函数,占位函数代码为也知道在哪里,那完全可以打个断点来调试一下。

在 Sources 中打开主 Document,找到:

_collect.q.push(arguments);

这里是 SDK 加载前所有埋点事件进入队列的统一入口。如果直接设置普通断点,每个事件都会让页面暂停,因此我添加了条件断点:

arguments[0] === "lark_website_mainpage_view"

alt text

刷新页面后,断点命中了两次。
第一次调用栈最终指向:

sendTeaEvent("lark_website_mainpage_view");

第二次调用栈指向一个 setTimeout(0) 回调:

window.collectEvent("lark_website_mainpage_view", {
  page_title: document.title,
  url_from,
});

结论

到这里就可以确认:不是 Tea SDK 把一个事件重复发送了,而是 SDK 接管之前,页面中的两段独立代码各生产了一次同名事件。

那么接下来就让之前负责这块脚本注入的同事选择去掉其中一个事件上报的逻辑就行了(如果是故意设计如此,那就不用删)。

为什么历史返回后埋点全部失效?

一开始,QA给我描述的是,当lark官网通过按钮页内跳转至其他页面,再通过返回按钮回到原来的页面后,原页面的所有埋点都会失效。

有了上一个bug排查的经验,我们可以直接通过查看网络请求list是否发送来复现这个bug。
去network选项卡,勾上 preserve log 选项,过滤list请求,刷新页面。

alt text

可以看到上报了发送了非常多的list请求,而且页面滚动、鼠标hover的埋点都可以正常上报埋点。

于是我们继续点击一个页内跳转的按钮,比如 Try for free,进入新页面把所有请求清空,再点击页面返回按钮:

alt text

发现回到原页面以后,一个list请求也看不到,而且滚动页面、鼠标hover甚至点击按钮都不会再进行埋点上报。

这说明bug确实存在。

为了确认点击浏览器返回按钮后页面经历了什么,我让大模型结合浏览器行为进行了检查。结果发现,在当前场景中,返回操作触发的是浏览器历史记录遍历,页面会重新创建并加载一个新的 Document,而不是由前端路由接管的 SPA 页面切换。因此,可以通过从浏览器历史记录进入该页面,复现相近的加载过程。

于是我直接从谷歌浏览器的历史记录里进入这个页面,看看会不会有一样的情况:

alt text

结果如图所示,一个list请求也没有。

那么现象其实就是,普通方式进入页面,埋点一切正常,从历史记录进入页面,埋点全部失效。两种进入方式感觉估计是什么东西的缓存造成了这种bug,但是具体发生了什么还真不好猜。

排查

让大模型去浏览器里一顿看脚本源码,它让我在两种状态下在控制台输入如下命令:

({
  collectEvent: String(window.collectEvent),
  queueLength: window.collectEvent?.q?.length,
  teaCommonReady: Boolean(window.teaCommonParams),
  cookieSDKReady: Boolean(window.__CookieConsent?.init),
  cookieInitialized: window.__CookieConsent?.state?.initialized,
  bannerLoaded: window.banner_loaded,
});
检查项 正常进入 历史返回
bannerLoaded true true
collectEvent function () { [native code] } function _collect(){_collect.q.push(arguments)}
teaCommonReady true false
cookieInitialized true false
cookieSDKReady true true
queueLength undefined 4

通过输出确实是一下看出好多东西不一样,问题是现在不懂这些变量啥意思或者干啥用的,所以还是得继续去查。

但是这个表格里的 queueLength 通过上一个bug调试我知道是啥,这是当时 collectEvent 函数还是占位函数状态下的一个属性,这个属性就是在注入真正的上报函数逻辑之前的事件上报的存储队列。

因为上报逻辑被注入以后,queue随着占位函数的消失跟着一起没了,所以undefined是正常的;但是历史返回的情况之下,这个属性的长度居然为4,说明上报逻辑没有被注入。这极有可能说明collectjs的脚本可能没有被正常加载,而不是业务事件没有传过来,因为queue是有长度的,说明事件是正常传到collectEvent函数里了的。

顺着这个思路,我感觉得让ai帮我理出collectjs这个文件的加载之前代码会做哪些事情:
大模型说:

-> 加载banner-sdk
→ Cookie Consent 初始化
→ ug-tea-common-params
→ collect.js
→ POST /list

这意味着,我应该先去搜索 banner-sdk关键词,看看是不是这个脚本没有加载出来

这一搜发现一个head区域的script脚本:

alt text

可以注意到这个脚本的逻辑,是加载好banner-sdk这个脚本以后,会触发一个banner.loaded的事件。而且会将bannerLoaded这个全局变量置为true,在上面的表格中可以发现,在历史返回的情况之下,这个变量确实会被置为true,说明这段触发事件的逻辑即便是在异常情况下也是执行了的。

既然我们找到了触发事件的位置,不妨搜索一下banner.loaded这个自定义事件是谁在监听:
alt text
果然找到了监听该事件的位置,看了一下事件回调函数中有调用这个函数:

initCookieBanner()

再稍微去看一下这个函数的逻辑,就会发现,这个函数就是用来初始化一些cookie配置:

function initCookieBanner() {
    window.__CookieConsent.init({
        env: "online",
        locale: lang.replace(/(.*)_(\w\w)/, function(r, m1, m2) {
            return m1 + "-" + m2.toUpperCase()
        }),
        onReady: onChange,
        region: "sg"
    })
}

并且在init完成之后会调用onchange函数,而onchange函数里面则会去加载埋点相关的脚本:
alt text
再结合最初的那张表,就可以确定了,这个initCookieBanner函数在某些情况下没有被执行,导致埋点也跟着一起失效了。
但是奇怪的是,我们看下面这段代码,会发现,无论 window.banner_loaded 这个全局变量是true还是false,按理来讲,都会去执行这个函数,如果没有执行,有理由怀疑这个函数在某种情况下可能在前面提前结束了。
alt text

这不怀疑还好,这一怀疑,果然发现了问题:
alt text
这里可以看到,当 _CookieConsent 这个全局变量还不存在时,函数会提前返回

如果正常进入页面可以看到埋点,说明这里没有被卡住,那么可以进一步说明应该是banner-sdk脚本加载好后里面的逻辑有去给window注入这个变量和init函数,因此这里没有提前返回,而且如果bannersdk已经加载好了,那么一定会走这个逻辑:

if (window.banner_loaded) {
    console.log("already loaded"); 
    initCookieBanner()
}

历史记录进入的页面,看不到埋点,说明这里提前返回了,也就说明,很有可能是这个

loadAllStatistics函数执行时,banner-sdk脚本还没有加载好,_CookieConsent这个变量还没有被定义,loadAllStatistics函数被提前返回,自定义事件的监听逻辑也就没有被执行,等banner-sdk脚本加载好了,再去触发banner.onload的事件已经没有用了。

那么现在基本可以确定,应该是

"loadAllStatistics函数执行"与"外部 banner SDK 加载完成"存在竞态关系

去浏览器里面看会发现,banner sdk的加载脚本是在head里头的,而loadAllStatistics函数执行是在body下面的script标签里发生的

当用户正常打开页面时,head中的script标签先执行,所以当loadAllStatistics函数执行时,cookie sdk早已完成加载,loadAllStatistics函数会走window.banner_loaded === true的分支,并且直接初始化cookie sdk,初始化后执行onChange函数,这个函数会负责埋点相关的脚本加载。

但是,需要明确的是,Head 中的加载器虽然先执行,但它通过 _loadScript 异步加载 Banner SDK,不会阻塞 Body 脚本。因此不排除会存在一种情况,二者的执行顺序倒转过来了。

比如,当用户通过历史记录来进入lark页面时,由于浏览器底层某种缓存机制会存在loadAllStatistics在banner sdk加载完成之前执行的情况,而loadAllStatistics函数在开头有一个 "如果banner sdk没有加载好就直接返回" 的逻辑,因此会错过cookie sdk的初始化,也就错过了埋点脚本的加载与执行。

验证

在 Sources 中搜索 loadAllStatistics,因为它是 Cookie Consent 和所有统计 SDK 的统一初始化入口。在函数开头的就绪的if判断处添加 Logpoint:

[
  "loadAllStatistics",
  performance.now(),
  Boolean(window.__CookieConsent),
  Boolean(window.__CookieConsent?.init),
  window.banner_loaded,
]

再搜索 banner.loaded 或 banner-sdk.1.4.3.js。在

dispatchEvent(loadEvent)

处添加 Logpoint:

[
  "banner.loaded",
  performance.now(),
  Boolean(window.__CookieConsent),
]
  • 正常进入页面的实际日志:
时间 日志 CookieConsent CookieConsent.init banner_loaded
447.7ms banner.loaded true 已存在 即将设为 true
1257ms loadAllStatistics true true true

Banner sdk加载好了,才去执行loadAllStatistics

  • 历史记录进入页面的实际日志:
时间 日志 CookieConsent CookieConsent.init banner_loaded
372.5ms loadAllStatistics undefined undefined false
389.7ms banner.loaded true 已存在 即将设为 true

banner SDK 比统计初始化晚约 17.2ms 就绪。具体毫秒数可能变化,但关键证据是 loadAllStatistics 先于 banner.loaded 执行。

根因总结

该 Bug 不是浏览器返回后 DOM 埋点监听失效,真正原因是 banner SDK 和统计初始化之间存在竞态:统计初始化先执行并提前返回,同时错过了随后派发的 banner.loaded 事件,因此 Tea 初始化链路无法恢复。