--- tags: Blue 的學習紀錄, Heroku --- # Heroku 除錯記錄：H18 Server Request Interrupted :::danger 問題沒有被解決，伺服器換成 Linode 後，一模一樣的程式碼就沒有問題了。猜測是 Heroku 的 middleware 造成的問題，但沒有明確的證據 ::: ## 環境 Node.js v14.15.1 ```json "connect-redis": "^5.2.0", "dotenv": "^9.0.2", "dropzone": "https://github.com/blueBlue0102/dropzone.git", "ejs": "^3.1.6", "express": "^4.17.1", "express-session": "^1.17.1", "formidable": "github:node-formidable/formidable", "joi": "^17.3.0", "passport": "^0.4.1", "passport-google-oauth20": "^2.0.0", "pg": "^8.6.0", "pg-hstore": "^2.3.3", "redis": "^3.1.2", "sequelize": "^6.6.2", "winston": "^3.3.3" ``` ## 問題 在有帳號系統的服務上，透過 HTTP POST 上傳圖片 當使用者上傳的圖片數量超過設定的上限時 理想上，預期 Server 會回傳 403 並且告知已超過上傳上限 在 local 端時一切運作正常，但是部屬到 Heroku 後，無法正確地顯示錯誤訊息 且收到的 status code 為 503 Service Unavailable 而不是我設定好的 403 Forbidden Logs 上顯示 ` sock=backend at=error code=H18 desc="Server Request Interrupted" method=POST ` ## 解決過程 ### Docker 這是一個典型 local 和 remote 兩端執行結果不一的問題，也許 Docker 可以幫助我解決這問題？ 研究了一陣子後，將環境要改成 Docker 來跑又需要解決更多的問題，所以決定擱置 ### 官方文件中對於 H18 的說明 <https://github.com/hunterloftis/heroku-node-errcodes/tree/master/h18> 裡面提到，發生的主因是 socket 在 response 完成之前就被 destroy 文件內提到解決的方法，是在 server response 的各環節中 catch 所有 error 但是即使我設置了各層 try catch block 甚至放大招來 catch 所有 error： ```javascript= process .on("unhandledRejection", (reason, p) => { console.error(reason, "Unhandled Rejection at Promise", p); }) .on("uncaughtException", (err) => { console.error(err, "Uncaught Exception thrown"); process.exit(1); }); ``` 仍然沒有任何 error stack 出現在記錄裡 ### Remote Debug 後來試著進行 remote debug，直接 trace 遠端上的 code 查看是怎麼跑 ([remote debug 的操作記錄在這篇](https://hackmd.io/@vegetableBird/ryR9X0gKO)) 終於得到了一點線索，stack trace 有東西出來了 源頭是 `express-session` 這個套件 得到 `Error: write ECONNRESET` 這個訊息 但明明是同樣的操作，這個 error stack 也不是每次都出來，行蹤不定 ### Stack overflow 估狗搜尋，雖然 stack overflow 有很多相關討論，但每篇解答都不太一樣 有說 Heroku 平台本身有 bug 的、只要先讀取過 req.body 就沒事的、CRLF 問題的，眾說紛紜 逐一嘗試也仍未解決，消耗完了我所有能量...，有種招式盡出已山窮水盡的感覺 ### TCP Socket？ 回歸原點，既然官方文件說明這個問題的根本原因是 > An H18 signifies that the socket connected, some data was sent as part of a response by the app, but then the socket was destroyed without completing the response. 剛好我對 TCP socket 也不熟悉，所以開始找些資源來學這些概念 經過一陣子的線上課程影片後，雖然略懂 TCP socket 的概念了，但還是不知道怎麼解決問題... ### 解決 最後，再次估狗 `Server request interrupted` 之後，在一篇 stack overflow 找到一個說法 server 的 response 不要立即回傳，而是讓他 sleep 個幾秒再回傳 ==終於，延遲幾秒後再回傳 response，就能正常顯示 403 訊息了== ## 小結 結合前面總總嘗試得來的線索 1. socket 在 response 尚未結束前就斷掉了 2. express-session 出現 write 相關的 error 3. 在回傳 response 之前，server sleep 個幾秒就正常運作 估計是 express-session 這個管理 cookie 的套件，沒有讓 server 等他執行完 cookie 的操作，server 若結束 response 就會產生 error 在 local 端時，因為速度夠快，所以沒有發生問題 但到了 heroku 端，因為資料庫都是在遠端而非本機端，所以需要來回連線的時間，而 server 又沒有等待與資料庫的連線完成才結束 response，因此造成 error ## Root Cause 雖然設定 setTimeout 可以避免錯誤產生，但這不是一個根本的解決方法 問題的源頭是，client 尚未 post 完 data，server 就已不對後續的 data 感興趣，而把 connection 關閉 ## 問題懸而未決 換成 Linode 的主機後，且資料庫（Postgre、Redis）也在同個主機上，沒有產生 error 雖然我自認已經做好，但也許實際上還是沒有 handle 好「與資料庫溝通」相關的 error。可是既然在 Linode 上都沒問題的話，就不想再花時間處理 Heroku 上的這個問題了