Cannot read property 'headers' of undefined - server shutdown

[timcolson]

This is a fresh install on Linux. DirtyDB. Service setup and started.

Log below...with additional logging added by me inside caching_middleware.js

145 function respond() {
146 req.method = old_req.method || req.method;
147 res.write = old_res.write || res.write;
148 res.end = old_res.end || res.end;
149 apiLogger.debug("TCOLSON:In the respond function...");
150 if (!(cacheKey in responseCache) ) { // Tim Colson check for hash key exists
151 //cacheKey = "TBD";
152 apiLogger.debug("TCOLSON:cacheKey("+cacheKey+") is not in responseCache");
153
154 }
155 var headers = responseCache[cacheKey].headers;

[2012-03-09 07:13:31.162] [INFO] console - Your Etherpad Lite git version is 6fd73ec
[2012-03-09 07:13:31.163] [INFO] console - Report bugs at https://github.com/Pita/etherpad-lite/issues
[2012-03-09 07:13:34.818] [INFO] console - Server is listening at 0.0.0.0:9001
[2012-03-09 07:13:34.819] [INFO] console - info - 'socket.io started'
[2012-03-09 07:13:38.100] [DEBUG] ueberDB - GET - pad:xfm52tVIYC - undefined - from database
[2012-03-09 07:13:38.118] [INFO] http - 200, GET /p/xfm52tVIYC
[2012-03-09 07:13:42.705] [DEBUG] socket.io - served static content /socket.io.js
[2012-03-09 07:13:44.310] [INFO] http - 304, HEAD /static/js/jquery.js
[2012-03-09 07:13:44.311] [INFO] http - 304, HEAD /static/js/security.js
[2012-03-09 07:13:44.311] [INFO] http - 304, HEAD /static/js/pad.js
[2012-03-09 07:13:44.311] [INFO] http - 304, HEAD /static/js/ace2_common.js
[2012-03-09 07:13:44.311] [INFO] http - 304, HEAD /static/js/pad_utils.js
[2012-03-09 07:13:44.313] [INFO] http - 304, HEAD /static/js/plugins.js
[2012-03-09 07:13:44.314] [INFO] http - 304, HEAD /static/js/undo-xpopup.js
[2012-03-09 07:13:44.314] [INFO] http - 304, HEAD /static/js/json2.js
[2012-03-09 07:13:44.314] [INFO] http - 304, HEAD /static/js/pad_cookie.js
[2012-03-09 07:13:44.314] [INFO] http - 304, HEAD /static/js/pad_editor.js
[2012-03-09 07:13:44.316] [INFO] http - 304, HEAD /static/js/pad_editbar.js
[2012-03-09 07:13:44.316] [INFO] http - 304, HEAD /static/js/pad_docbar.js
[2012-03-09 07:13:44.316] [INFO] http - 304, HEAD /static/js/pad_modals.js
[2012-03-09 07:13:44.317] [INFO] http - 304, HEAD /static/js/collab_client.js
[2012-03-09 07:13:44.318] [INFO] http - 304, HEAD /static/js/ace.js
[2012-03-09 07:13:44.319] [INFO] http - 304, HEAD /static/js/pad_userlist.js
[2012-03-09 07:13:44.319] [INFO] http - 304, HEAD /static/js/pad_impexp.js
[2012-03-09 07:13:44.319] [INFO] http - 304, HEAD /static/js/pad_savedrevs.js
[2012-03-09 07:13:44.319] [INFO] http - 304, HEAD /static/js/pad_connectionstatus.js
[2012-03-09 07:13:44.321] [INFO] http - 304, HEAD /static/js/chat.js
[2012-03-09 07:13:44.321] [INFO] http - 304, HEAD /static/js/excanvas.js
[2012-03-09 07:13:44.321] [INFO] http - 304, HEAD /static/js/farbtastic.js
[2012-03-09 07:13:44.321] [INFO] http - 304, HEAD /static/js/prefixfree.js
[2012-03-09 07:13:44.322] [INFO] http - 404, HEAD /static/js/jquery
[2012-03-09 07:13:44.323] [INFO] http - 404, HEAD /static/js/security
[2012-03-09 07:13:44.324] [INFO] http - 404, HEAD /static/js/pad
[2012-03-09 07:13:44.324] [INFO] http - 404, HEAD /static/js/ace2_common
[2012-03-09 07:13:44.324] [INFO] http - 404, HEAD /static/js/pad_utils
[2012-03-09 07:13:44.324] [INFO] http - 404, HEAD /static/js/plugins
[2012-03-09 07:13:44.326] [INFO] http - 404, HEAD /static/js/undo-xpopup
[2012-03-09 07:13:44.326] [INFO] http - 404, HEAD /static/js/json2
[2012-03-09 07:13:44.326] [INFO] http - 404, HEAD /static/js/pad_cookie
[2012-03-09 07:13:44.326] [INFO] http - 404, HEAD /static/js/pad_editor
[2012-03-09 07:13:44.327] [INFO] http - 404, HEAD /static/js/pad_editbar
[2012-03-09 07:13:44.328] [INFO] http - 404, HEAD /static/js/pad_docbar
[2012-03-09 07:13:44.328] [INFO] http - 404, HEAD /static/js/pad_modals
[2012-03-09 07:13:44.329] [INFO] http - 404, HEAD /static/js/ace
[2012-03-09 07:13:44.329] [INFO] http - 404, HEAD /static/js/collab_client
[2012-03-09 07:13:44.329] [INFO] http - 404, HEAD /static/js/pad_userlist
[2012-03-09 07:13:44.331] [INFO] http - 404, HEAD /static/js/pad_impexp
[2012-03-09 07:13:44.331] [INFO] http - 404, HEAD /static/js/pad_savedrevs
[2012-03-09 07:13:44.331] [INFO] http - 404, HEAD /static/js/pad_connectionstatus
[2012-03-09 07:13:44.331] [INFO] http - 404, HEAD /static/js/chat
[2012-03-09 07:13:44.331] [INFO] http - 404, HEAD /static/js/excanvas
[2012-03-09 07:13:44.333] [INFO] http - 404, HEAD /static/js/farbtastic
[2012-03-09 07:13:44.333] [INFO] http - 404, HEAD /static/js/prefixfree
[2012-03-09 07:13:44.334] [DEBUG] cacheing_middleware - TCOLSON:In the respond function...
[2012-03-09 07:13:44.334] [DEBUG] cacheing_middleware - TCOLSON:cacheKey(L21pbmlmaWVkL3BhZC5qcz9jYWxsYmFjaz1yZXF1aXJlLmRlZmluZQ) is not in responseCache
[2012-03-09 07:13:44.337] [ERROR] console - TypeError: Cannot read property 'headers' of undefined
at respond (/apps/share/etherpad-lite/node/utils/caching_middleware.js:155:39)
at ServerResponse. (/apps/share/etherpad-lite/node/utils/caching_middleware.js:133:48)
at /apps/share/etherpad-lite/node_modules/yajsml/server.js:384:18
at /apps/share/etherpad-lite/node_modules/yajsml/server.js:435:13
at completed (/apps/share/etherpad-lite/node_modules/yajsml/request.js:279:5)
at /apps/share/etherpad-lite/node_modules/yajsml/request.js:266:9
at IncomingMessage. (/apps/share/etherpad-lite/node_modules/yajsml/request.js:248:20)
at IncomingMessage.emit (events.js:88:20)
at HTTPParser.onMessageComplete (http.js:137:23)
at Socket.ondata (http.js:1150:24)
[2012-03-09 07:13:44.337] [INFO] console - graceful shutdown...
[2012-03-09 07:13:44.337] [INFO] console - db sucessfully closed.

[cweider]

Ok, this is because the files with the cached content are not getting cleaned up (./bin/run.sh should do this). One fix would be to cherry-pick 57d0a2e from #541.

[timcolson]

Thanks - I gave that a try, but no luck, so I deleted the entire etherpad-lite directory and started with a fresh pull with git... now it just hangs after trying to start a new pad. FYI - above, I was trying to create a new auto-pad too, so there shouldn't be any cached content, right?

2012-Mar-09 13:25 : Update -- I tried with Firefox and Safari -- works. Chrome is the only one hangs at that spot.

[etherpad-lite@workpad-in etherpad-lite]$ bin/run.sh
Ensure that all dependencies are up to date...
Ensure jQuery is downloaded and up to date...
Ensure prefixfree is downloaded and up to date...
Clear minfified cache...
ensure custom css/js files are created...
start...
[2012-03-09 11:56:24.360] [INFO] console - Your Etherpad Lite git version is 6fd73ec
[2012-03-09 11:56:24.363] [INFO] console - Report bugs at https://github.com/Pita/etherpad-lite/issues
[2012-03-09 11:56:25.388] [INFO] console - Server is listening at 0.0.0.0:9001
[2012-03-09 11:56:25.389] [INFO] console - info - 'socket.io started'
[2012-03-09 11:56:37.645] [INFO] http - 200, GET /p/iOGu7iTUpk
[2012-03-09 11:56:38.409] [INFO] http - 307, GET /minified/pad?callback=require.define --> and it just stops here...

[timcolson]

I cleared the chrome cache for the past day, tried again, and it works.

So the question now becomes... what is it about the client that fubar'd getting a reply from the server?

[2012-03-09 12:27:49.609] [INFO] http - 200, GET /minified/pad.js?callback=require.define
[2012-03-09 12:27:50.402] [DEBUG] socket.io - client authorized
[2012-03-09 12:27:50.403] [INFO] socket.io - handshake authorized '1443459931446525022'
[2012-03-09 12:27:50.608] [DEBUG] socket.io - setting request 'GET' '/socket.io/1/xhr-polling/1443459931446525022?t=1331324870727'
[2012-03-09 12:27:50.608] [DEBUG] socket.io - setting poll timeout
[2012-03-09 12:27:50.608] [DEBUG] socket.io - client authorized for
[2012-03-09 12:27:50.609] [DEBUG] socket.io - clearing poll timeout
[2012-03-09 12:27:50.609] [DEBUG] socket.io - xhr-polling writing '1::'
[2012-03-09 12:27:50.609] [DEBUG] socket.io - set close timeout for client '1443459931446525022'

[timcolson]

I was away from this for a bit, back now trying to setup MySQL connection (failed, says it cannot connect, so went back to the dirty/file-based DB).

I've found I can reproduce this issue.

1. Startup the server.
2. Create a random pad (with Chrome)
3. Stop the server
4. Start the server
5. In Safari go to the url with the pad id -- http://etherpadserver.domain.com/p/mfwa3Nrc3d - watch logs get the existing pad just fine
6. In Chrome go to the url with the pad id -- http://etherpadserver.domain.com/p/mfwa3Nrc3d
7. Watch etherpad-lite die

Looks to me like a null-pointer error due to an issue with Chrome not sending the expected headers. Etherpad-Lite shouldn't just die in this situation.

[2012-04-13 06:48:57.029] [INFO] console - Your Etherpad Lite git version is 6fd73ec
[2012-04-13 06:48:57.031] [INFO] console - Report bugs at https://github.com/Pita/etherpad-lite/issues
[2012-04-13 06:48:57.177] [INFO] console - Server is listening at 0.0.0.0:9001
[2012-04-13 06:48:57.178] [INFO] console - info - 'socket.io started'
[2012-04-13 06:49:15.366] [DEBUG] ueberDB - GET - pad:mfwa3Nrc3d - {"atext":{"text":"Welcome to Etherpad Lite!\n\nThis pad text is synchronized as you type, so that everyone viewing this page sees the same text. This allows you to collaborate seamlessly on documents!\n\nEtherpad Lite on Github: http://j.mp/ep-lite\n\n","attribs":"|6+6c"},"pool":{"numToAttrib":{},"nextNum":0},"head":0,"chatHead":-1,"publicStatus":false,"passwordHash":null} - from database
[2012-04-13 06:49:15.369] [INFO] http - 200, GET /p/mfwa3Nrc3d
[2012-04-13 06:49:15.814] [DEBUG] socket.io - served static content /socket.io.js
[2012-04-13 06:49:16.144] [DEBUG] socket.io - client authorized
[2012-04-13 06:49:16.144] [INFO] socket.io - handshake authorized '4857344132051257286'
[2012-04-13 06:49:16.160] [INFO] http - 200, GET /static/custom/pad.css
[2012-04-13 06:49:16.166] [INFO] http - 200, GET /static/custom/pad.css
[2012-04-13 06:49:16.431] [DEBUG] socket.io - setting request 'GET' '/socket.io/1/xhr-polling/4857344132051257286?t=1334324956297'
[2012-04-13 06:49:16.431] [DEBUG] socket.io - setting poll timeout
[2012-04-13 06:49:16.431] [DEBUG] socket.io - client authorized for
[2012-04-13 06:49:16.432] [DEBUG] socket.io - clearing poll timeout
[2012-04-13 06:49:16.432] [DEBUG] socket.io - xhr-polling writing '1::'
[2012-04-13 06:49:16.432] [DEBUG] socket.io - set close timeout for client '4857344132051257286'
[2012-04-13 06:49:16.619] [DEBUG] socket.io - xhr-polling received data packet '4:::{"component":"pad","type":"CLIENT_READY","padId":"mfwa3Nrc3d","sessionID":null,"password":null,"token":"t.vUznAly2q5k4g61UJqWN","protocolVersion":2}'
[2012-04-13 06:49:16.620] [DEBUG] ueberDB - GET - token2author:t.vUznAly2q5k4g61UJqWN - "a.uwx67oGhZ0WjZfNp" - from database
[2012-04-13 06:49:16.620] [DEBUG] ueberDB - SETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["timestamp"] - 1334324956620
[2012-04-13 06:49:16.620] [INFO] message - from 4857344132051257286: {"component":"pad","type":"CLIENT_READY","padId":"mfwa3Nrc3d","sessionID":null,"password":null,"token":"t.vUznAly2q5k4g61UJqWN","protocolVersion":2}
[2012-04-13 06:49:16.620] [DEBUG] ueberDB - GET - token2author:t.vUznAly2q5k4g61UJqWN - "a.uwx67oGhZ0WjZfNp" - from database
[2012-04-13 06:49:16.621] [DEBUG] ueberDB - GET - pad:mfwa3Nrc3d - {"atext":{"text":"Welcome to Etherpad Lite!\n\nThis pad text is synchronized as you type, so that everyone viewing this page sees the same text. This allows you to collaborate seamlessly on documents!\n\nEtherpad Lite on Github: http://j.mp/ep-lite\n\n","attribs":"|6+6c"},"pool":{"numToAttrib":{},"nextNum":0},"head":0,"chatHead":-1,"publicStatus":false,"passwordHash":null} - from database
[2012-04-13 06:49:16.621] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324652220} - from database
[2012-04-13 06:49:16.621] [DEBUG] ueberDB - GET - pad2readonly:mfwa3Nrc3d - "r.bA5T3dpq8UicDKSC" - from database
[2012-04-13 06:49:16.621] [DEBUG] ueberDB - SET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - to database
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - SETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["timestamp"] - 1334324956620
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - from database
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - SET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - to database
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - from database
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - GETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["colorId"] - "#1f359d"
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - from database
[2012-04-13 06:49:16.622] [DEBUG] ueberDB - GETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["name"] - "Tim3"
[2012-04-13 06:49:16.623] [INFO] message - to 4857344132051257286: {"accountPrivs":{"maxRevisions":100},"initialRevisionList":[],"initialOptions":{"guestPolicy":"deny"},"collab_client_vars":{"initialAttributedText":{"text":"Welcome to Etherpad Lite!\n\nThis pad text is synchronized as you type, so that everyone viewing this page sees the same text. This allows you to collaborate seamlessly on documents!\n\nEtherpad Lite on Github: http://j.mp/ep-lite\n\n","attribs":"|6+6c"},"clientIp":"127.0.0.1","padId":"mfwa3Nrc3d","historicalAuthorData":{},"apool":{"numToAttrib":{},"nextNum":0},"rev":0,"globalPadId":"mfwa3Nrc3d"},"colorPalette":["#ffc7c7","#fff1c7","#e3ffc7","#c7ffd5","#c7ffff","#c7d5ff","#e3c7ff","#ffc7f1","#ff8f8f","#ffe38f","#c7ff8f","#8fffab","#8fffff","#8fabff","#c78fff","#ff8fe3","#d97979","#d9c179","#a9d979","#79d991","#79d9d9","#7991d9","#a979d9","#d979c1","#d9a9a9","#d9cda9","#c1d9a9","#a9d9b5","#a9d9d9","#a9b5d9","#c1a9d9","#d9a9cd","#4c9c82","#12d1ad","#2d8e80","#7485c3","#a091c7","#3185ab","#6818b4","#e6e76d","#a42c64","#f386e5","#4ecc0c","#c0c236","#693224","#b5de6a","#9b88fd","#358f9b","#496d2f","#e267fe","#d23056","#1a1a64","#5aa335","#d722bb","#86dc6c","#b5a714","#955b6a","#9f2985","#4b81c8","#3d6a5b","#434e16","#d16084","#af6a0e","#8c8bd8"],"clientIp":"127.0.0.1","userIsGuest":true,"userColor":"#1f359d","padId":"mfwa3Nrc3d","initialTitle":"Pad: mfwa3Nrc3d","opts":{},"chatHistory":[],"numConnectedUsers":1,"isProPad":false,"readOnlyId":"r.bA5T3dpq8UicDKSC","serverTimestamp":1334324956622,"globalPadId":"mfwa3Nrc3d","userId":"a.uwx67oGhZ0WjZfNp","cookiePrefsToSet":{"fullWidth":false,"hideSidebar":false},"abiwordAvailable":"no","hooks":{},"userName":"Tim3"}
[2012-04-13 06:49:16.623] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - from database
[2012-04-13 06:49:16.623] [DEBUG] ueberDB - GETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["colorId"] - "#1f359d"
[2012-04-13 06:49:16.623] [DEBUG] ueberDB - GET - globalAuthor:a.uwx67oGhZ0WjZfNp - {"colorId":"#1f359d","name":"Tim3","timestamp":1334324956620} - from database
[2012-04-13 06:49:16.623] [DEBUG] ueberDB - GETSUB - globalAuthor:a.uwx67oGhZ0WjZfNp["name"] - "Tim3"
[2012-04-13 06:49:16.624] [DEBUG] socket.io - setting request 'GET' '/socket.io/1/xhr-polling/4857344132051257286?t=1334324956484'
[2012-04-13 06:49:16.625] [DEBUG] socket.io - setting poll timeout
[2012-04-13 06:49:16.625] [DEBUG] socket.io - clearing poll timeout
[2012-04-13 06:49:16.625] [DEBUG] socket.io - xhr-polling writing '4:::{"accountPrivs":{"maxRevisions":100},"initialRevisionList":[],"initialOptions":{"guestPolicy":"deny"},"collab_client_vars":{"initialAttributedText":{"text":"Welcome to Etherpad Lite!\n\nThis pad text is synchronized as you type, so that everyone viewing this page sees the same text. This allows you to collaborate seamlessly on documents!\n\nEtherpad Lite on Github: http://j.mp/ep-lite\\n\\n","attribs":"|6+6c"},"clientIp":"127.0.0.1","padId":"mfwa3Nrc3d","historicalAuthorData":{},"apool":{"numToAttrib":{},"nextNum":0},"rev":0,"globalPadId":"mfwa3Nrc3d"},"colorPalette":["#ffc7c7","#fff1c7","#e3ffc7","#c7ffd5","#c7ffff","#c7d5ff","#e3c7ff","#ffc7f1","#ff8f8f","#ffe38f","#c7ff8f","#8fffab","#8fffff","#8fabff","#c78fff","#ff8fe3","#d97979","#d9c179","#a9d979","#79d991","#79d9d9","#7991d9","#a979d9","#d979c1","#d9a9a9","#d9cda9","#c1d9a9","#a9d9b5","#a9d9d9","#a9b5d9","#c1a9d9","#d9a9cd","#4c9c82","#12d1ad","#2d8e80","#7485c3","#a091c7","#3185ab","#6818b4","#e6e76d","#a42c64","#f386e5","#4ecc0c","#c0c236","#693224","#b5de6a","#9b88fd","#358f9b","#496d2f","#e267fe","#d23056","#1a1a64","#5aa335","#d722bb","#86dc6c","#b5a714","#955b6a","#9f2985","#4b81c8","#3d6a5b","#434e16","#d16084","#af6a0e","#8c8bd8"],"clientIp":"127.0.0.1","userIsGuest":true,"userColor":"#1f359d","padId":"mfwa3Nrc3d","initialTitle":"Pad: mfwa3Nrc3d","opts":{},"chatHistory":[],"numConnectedUsers":1,"isProPad":false,"readOnlyId":"r.bA5T3dpq8UicDKSC","serverTimestamp":1334324956622,"globalPadId":"mfwa3Nrc3d","userId":"a.uwx67oGhZ0WjZfNp","cookiePrefsToSet":{"fullWidth":false,"hideSidebar":false},"abiwordAvailable":"no","hooks":{},"userName":"Tim3"}'
[2012-04-13 06:49:16.625] [DEBUG] socket.io - set close timeout for client '4857344132051257286'
[2012-04-13 06:49:16.625] [DEBUG] socket.io - discarding transport
[2012-04-13 06:49:16.625] [DEBUG] socket.io - cleared close timeout for client '4857344132051257286'
[2012-04-13 06:49:16.898] [DEBUG] socket.io - setting request 'GET' '/socket.io/1/xhr-polling/4857344132051257286?t=1334324956763'
[2012-04-13 06:49:16.899] [DEBUG] socket.io - setting poll timeout
[2012-04-13 06:49:16.899] [DEBUG] socket.io - discarding transport
[2012-04-13 06:49:16.899] [DEBUG] socket.io - cleared close timeout for client '4857344132051257286'
[2012-04-13 06:49:22.001] [DEBUG] ueberDB - GET - pad:mfwa3Nrc3d - {"atext":{"text":"Welcome to Etherpad Lite!\n\nThis pad text is synchronized as you type, so that everyone viewing this page sees the same text. This allows you to collaborate seamlessly on documents!\n\nEtherpad Lite on Github: http://j.mp/ep-lite\n\n","attribs":"|6+6c"},"pool":{"numToAttrib":{},"nextNum":0},"head":0,"chatHead":-1,"publicStatus":false,"passwordHash":null} - from database
[2012-04-13 06:49:22.002] [INFO] http - 304, GET /p/mfwa3Nrc3d
[2012-04-13 06:49:22.125] [DEBUG] socket.io - served static content /socket.io.js
[2012-04-13 06:49:22.134] [INFO] http - 304, HEAD /static/js/jquery.js
[2012-04-13 06:49:22.134] [INFO] http - 304, HEAD /static/js/security.js
[2012-04-13 06:49:22.134] [INFO] http - 304, HEAD /static/js/pad.js
[2012-04-13 06:49:22.134] [INFO] http - 304, HEAD /static/js/ace2_common.js
[2012-04-13 06:49:22.135] [INFO] http - 304, HEAD /static/js/pad_utils.js
[2012-04-13 06:49:22.137] [INFO] http - 304, HEAD /static/js/plugins.js
[2012-04-13 06:49:22.137] [INFO] http - 304, HEAD /static/js/undo-xpopup.js
[2012-04-13 06:49:22.138] [INFO] http - 304, HEAD /static/js/json2.js
[2012-04-13 06:49:22.138] [INFO] http - 304, HEAD /static/js/pad_cookie.js
[2012-04-13 06:49:22.138] [INFO] http - 304, HEAD /static/js/pad_editor.js
[2012-04-13 06:49:22.140] [INFO] http - 304, HEAD /static/js/pad_editbar.js
[2012-04-13 06:49:22.140] [INFO] http - 304, HEAD /static/js/pad_docbar.js
[2012-04-13 06:49:22.140] [INFO] http - 304, HEAD /static/js/pad_modals.js
[2012-04-13 06:49:22.141] [INFO] http - 304, HEAD /static/js/collab_client.js
[2012-04-13 06:49:22.143] [INFO] http - 304, HEAD /static/js/ace.js
[2012-04-13 06:49:22.143] [INFO] http - 304, HEAD /static/js/pad_userlist.js
[2012-04-13 06:49:22.143] [INFO] http - 304, HEAD /static/js/pad_impexp.js
[2012-04-13 06:49:22.143] [INFO] http - 304, HEAD /static/js/pad_savedrevs.js
[2012-04-13 06:49:22.143] [INFO] http - 304, HEAD /static/js/pad_connectionstatus.js
[2012-04-13 06:49:22.145] [INFO] http - 304, HEAD /static/js/chat.js
[2012-04-13 06:49:22.146] [INFO] http - 304, HEAD /static/js/excanvas.js
[2012-04-13 06:49:22.146] [INFO] http - 304, HEAD /static/js/farbtastic.js
[2012-04-13 06:49:22.146] [INFO] http - 304, HEAD /static/js/prefixfree.js
[2012-04-13 06:49:22.147] [INFO] http - 404, HEAD /static/js/jquery
[2012-04-13 06:49:22.148] [INFO] http - 404, HEAD /static/js/security
[2012-04-13 06:49:22.149] [INFO] http - 404, HEAD /static/js/pad
[2012-04-13 06:49:22.149] [INFO] http - 404, HEAD /static/js/ace2_common
[2012-04-13 06:49:22.149] [INFO] http - 404, HEAD /static/js/pad_utils
[2012-04-13 06:49:22.150] [INFO] http - 404, HEAD /static/js/plugins
[2012-04-13 06:49:22.151] [INFO] http - 404, HEAD /static/js/undo-xpopup
[2012-04-13 06:49:22.151] [INFO] http - 404, HEAD /static/js/json2
[2012-04-13 06:49:22.151] [INFO] http - 404, HEAD /static/js/pad_cookie
[2012-04-13 06:49:22.152] [INFO] http - 404, HEAD /static/js/pad_editor
[2012-04-13 06:49:22.153] [INFO] http - 404, HEAD /static/js/pad_editbar
[2012-04-13 06:49:22.154] [INFO] http - 404, HEAD /static/js/pad_docbar
[2012-04-13 06:49:22.154] [INFO] http - 404, HEAD /static/js/pad_modals
[2012-04-13 06:49:22.154] [INFO] http - 404, HEAD /static/js/ace
[2012-04-13 06:49:22.154] [INFO] http - 404, HEAD /static/js/collab_client
[2012-04-13 06:49:22.157] [INFO] http - 404, HEAD /static/js/pad_userlist
[2012-04-13 06:49:22.157] [INFO] http - 404, HEAD /static/js/pad_impexp
[2012-04-13 06:49:22.157] [INFO] http - 404, HEAD /static/js/pad_savedrevs
[2012-04-13 06:49:22.157] [INFO] http - 404, HEAD /static/js/pad_connectionstatus
[2012-04-13 06:49:22.158] [INFO] http - 404, HEAD /static/js/chat
[2012-04-13 06:49:22.159] [INFO] http - 404, HEAD /static/js/excanvas
[2012-04-13 06:49:22.160] [INFO] http - 404, HEAD /static/js/farbtastic
[2012-04-13 06:49:22.160] [INFO] http - 404, HEAD /static/js/prefixfree
[2012-04-13 06:49:22.164] [ERROR] console - TypeError: Cannot read property 'headers' of undefined
at respond (/apps/share/etherpad-lite/node/utils/caching_middleware.js:147:46)
at ServerResponse. (/apps/share/etherpad-lite/node/utils/caching_middleware.js:130:48)
at /apps/share/etherpad-lite/node_modules/yajsml/server.js:384:18
at /apps/share/etherpad-lite/node_modules/yajsml/server.js:435:13
at completed (/apps/share/etherpad-lite/node_modules/yajsml/request.js:279:5)
at /apps/share/etherpad-lite/node_modules/yajsml/request.js:266:9
at IncomingMessage. (/apps/share/etherpad-lite/node_modules/yajsml/request.js:248:20)
at IncomingMessage.emit (events.js:88:20)
at HTTPParser.onMessageComplete (http.js:137:23)
at Socket.ondata (http.js:1150:24)
[2012-04-13 06:49:22.164] [INFO] console - graceful shutdown...
[2012-04-13 06:49:22.164] [INFO] console - db sucessfully closed.

[timcolson]

Aside, I assume the 404's on the HEAD requests for the directories are "normal", and I know the 304's on the files is just fine... question is -- can I set the logging so they are demoted to DEBUG instead of INFO?

[marcelklehr]

Is this still an issue?

[timcolson]

Well -- I have not seen the server shutdown after updating both Node (0.6.18) and etherpad-lite (git describe --tags
1.0-542-g5e5a444) a few weeks ago.