what to do next

this feels like the ultimate question

though I'm not sure it's as simple as that, because there is the issue of planning. That is, if I just decide what to do next, and then do it, then I'll need to decide the next thing to do after that, and it may be more efficient to plan a string of things to do..

yet the act of creating the plan itself can be viewed as an item to do next. The next thing I will do is create a plan of things to do.

though I'm not sure it's as simple as that either, because thought that happens in the brain doesn't just make plans about what to do next — the thoughts themselves have effects on the brain, and the brain is running many processes, and lots of unconscious processes, and all of these things are effected in various ways by thinking.. and it's so complicated..


I feel like I want a less complicated mind..

these are a few of my favorite things

• solving a problem
• understanding something
• discovering something new
• making something more efficient

these are a few mental tools I use

• focus
• acceptance
• detachement (depersonalization)

these are a few philosophies I use

• I'm not sure of anything
• both sides of every issue have merit
• if I was in someone else's shoes, I would do what they do

I keep writing stuff like this.. this blog is full of it.. I feel like I'm trying inch by inch to figure out my "program".

brain hacking

brain > echo $HOW_IMPORTANT_DO_THINGS_SEEM

super important

brain > export HOW_IMPORTANT_DO_THINGS_SEEM=somewhat important

failed: permission denied

brain > sudo export HOW_IMPORTANT_DO_THINGS_SEEM=somewhat important

failed: mysterious reason

brain > explain mysterious reason

explain: command not found

brain > sleep

failed: worried about something important

brain > _

doh..

I was looking in the new fancy error log thing, where I had been seeing a lot of "bad inputs", and decided to spruce up the message to show what the input actually was that was bad.

My original thought was that my app was successfully guarding against some clever chap circumventing my JavaScript input validation,

but no..

my JavaScript input validation was slightly different than my server input validation. The client wanted answers to be in the range 150 to 450 characters, and this was checked using essentially s.length >= 150 && s.length <= 450. However, the server was using a regular expression: /^.{150,450}$/. But that dot doesn't match newlines :(

Why were they different on the client and server? Well, the client actually makes two checks, and if either fails, gives the user a message saying "too short" or "too long". The server doesn't provide any nice feedback, it just throws a "bad input" exception if it's not correct, so it does it in one check.

alas..

and I'm so good at regular expressions too.

the new expression is /^[\S\s]{150,450}$/

At this time, I really wish I had some way of sending a message to all the people, letting them know why some of them were getting strange errors when they tried to submit their answers. I'm wishing I had the global chat box thing.

work notes

the user who can't login to my app got my e-mail and tried logging in again. I found this error in my log:

error: Error: failed to find request token in session
    at OAuthStrategy.authenticate (/app/node_modules/passport-oauth/lib/passport-oauth/strategies/oauth.js:122:54)
    at attempt (/app/node_modules/passport/lib/passport/middleware/authenticate.js:243:16)
    at Passport.authenticate (/app/node_modules/passport/lib/passport/middleware/authenticate.js:244:7)
    at callbacks (/app/node_modules/express/lib/router/index.js:272:11)
    at param (/app/node_modules/express/lib/router/index.js:246:11)
    at pass (/app/node_modules/express/lib/router/index.js:253:5)
    at Router._dispatch (/app/node_modules/express/lib/router/index.js:280:5)
    at Object.middleware [as handle] (/app/node_modules/express/lib/router/index.js:45:10)
    at Context.next (/app/node_modules/express/node_modules/connect/lib/http.js:204:15)
    at Context.actions.pass (/app/node_modules/passport/lib/passport/context/http/actions.js:77:8)

if we look at passport-oauth/strategies/oauth.js:122, we see:

if (!req.session[self._key]) { return self.error(new Error('failed to find request token in session')); }

After reading a comment above this line, I think I understand what is going on:

- the app got a request token and secret from oDesk

- the app directed the user to oDesk's site with the request token, and a return url

- the user authenticated the app on oDesk, and was redirected to the given url

- oDesk appended query parameters to the redirect link including the request token and verifier

- now the code in oauth.js is going to fetch the access token from oDesk

- BUT, it needs three things: a request token (included as query parameter from oDesk), a verifier (also included in query parameter), and the secret. The secret is not sent back from oDesk. It's secret. My app is supposed to know it already. My app.. or rather the module I'm using.. keeps the secret in a session. The above is verifying that it's in the session, but it isn't.

How could that be?

- maybe they don't have cookies enabled? I tried disabling cookies, and I couldn't log into oDesk itself in order to verify the app. I know this user was able to verify the app, because the code above only runs after oDesk redirects the user back to my site, which happens after they verify the app, so they must have logged into oDesk.. so they must have cookies.

- maybe cookies are disabled just for my site? Unlikely. I don't see an easy way to enable cookies just for certain sites.

- I feel like it might reveal something to see their session.. I think I'll ask them for it. I need instructions for them to give it to me. How about:

1. copy-paste "chrome://settings/cookies" into the address bar and press enter

2. in the search box where it says "Search cookies", type "heroku"

3. look for an item in the list beginning with "random-name-6789" and click on it

4. a little bubble should appear beneath where it says "1 cookie" that says "connect.sid", click on that

5. now highlight all the text that appears in the box, by clicking the mouse just to the left of "Name" and dragging down and to the right, until everything above the "Remove" button is highlighted.

6. copy it, and paste it into this e-mail and send it to me.

ok, sent.. we'll see what comes of that..

hm.. now that I've sent that e-mail, I could probably have made it easier on them to have them login again, and I could record their session id in the log.. or could I? I'd like to modify the code above, but I'm not sure that will work exactly when I check it into heroku.. maybe it will..

or maybe I could log session id's for all errors.. yes, that seems better..

work notes

apparently one user couldn't log in. I tried logging in with a brand new test oDesk account, and succeeded, so I don't think login is broken completely.. somehow this one user is getting an error, and from what they've told me, it sounds like a legitimate error. My best guess about what could be causing it is this code:


var o = new odesk(odeskApiKey, odeskApiSecret)
o.OAuth.accessToken = token
o.OAuth.accessTokenSecret = tokenSecret
o.get('auth/v1/info', function(err, data) {
if (err) return done(err)
var user = {
_id : data.auth_user.uid,
name : data.auth_user.first_name + " " + data.auth_user.last_name,
img : data.info.portrait_100_img,
country : data.info.location.country,
profile : data.info.profile_url
}
db.collection('users').insert(user, function () {
done(null, user)
})
})

..specifically the part in bold. As far as I can tell, that is the only piece of code that could be different for a particular user. I could see an exception being thrown if data.auth_user was null, or data.info, or more likely data.info.location.

I tried to find the exception in the logs — assuming there was an exception thrown somewhere — but heroku only gives me the most recent 1500 lines, and those quickly get consumed with normal request logs. I wish it kept the most recent 1500 error logs separately.

I'm thinking about storing my own error logs within the database. I could use a mongodb capped collection to make sure they don't grow too big if some error becomes very frequent.

First, I want to find out where exactly an exception thrown in the code above would have gone.. does express catch it? (If not, how does it serve up an HTTP 500?)

Ok, express does catch the exception. So express probably has some way for me to register a callback to be executed when exceptions happen..

Or better yet, there's an addon called Loggly that will store.. for free.. 25mb of logs.. which looks like it will be about 100,000 log items. And it keeps them for 24 hours. So assuming I don't hit my cap, I could tell the person to try logging in again, and the error should show up in Loggly..

But they probably won't login until tomorrow morning, and I'll probably wake up several hours after they do. I wonder how quickly I consume 100,000 logs. Let's look at the timestamp of the oldest log of the 1500 heroku will give me.. looks like 2.2 hours, so 1500/2.2 = 682 per hour, over 24 hours is 16,363, so the entry will probably survive until I get up. Of course, given that it's about 2am, the last 2.2 hours probably aren't the most eventful of the day. If the site had ten times as much traffic during the day, it would give me a 14 hour window between when they login, and when I check..

And I would need to make sure to check — if I forgot, and checked the next day, it would be gone..

And I'll need to search for the error in the logs. Loggly has a search tool, but the error will consume multiple lines. It's probably easy to find the first line by searching for "error", but will Loggly show me the lines immediately after that? Hm.. fiddling with the interface, it's not immediately clear to me how to even search for "error". They have a sort of command line, and I don't know what I'm meant to type in it.

I think I'll just log the exceptions to a "logs" collection, and make it a capped collection in mongodb.

Hm.. we're going to run "db.createCollection('logs', {capped:true, size:10000})" in the database. I wonder what a good place to note that is.. I could put it in the readme file.. it would be better if the code itself created this. I'll have to try creating it twice, and see if that's a problem. Or maybe there's a way to check for its existence first.. ok, apparently it doesn't care if I call it twice, so I'll just create it at the beginning, right after connecting to the database.. there's no callback for waiting to connect to the database, so I'll just assume it's connected, or that I'm allowed to pretend as though it is..

ok, done. generic error logging added. Let's push to heroku, and test it there.. Success! Now I'll just e-mail that person, tell them to try logging in, and see what my error log collection has to say tomorrow.

..I've been thinking about logging and monitoring.. I'd like some elegant catch-all solution to having a sense for whether the app is working, and how close it is to breaking down. I feel like the logs are probably a good heart-beat for the app, and they have timing information in them.

I got rid of Loggly and added Logentries. It doesn't have a size quota, just a day quota, and even the free version is 7 days. Also, it says it will e-mail me if any heroku specific bad log messages appear, saying things like "memory limit exceeded" and such.

I wish Logentries, or one of these other loggers, would parse the timing information from the request logs, and tell me averages times for various requests.. it seems like the monitoring tools want to profile my app by embedding code in it, which I'm wary about.

ok.. well.. I'm going to go to bed soon. I told the people using this app that they could add more people to it.. currently there are about 250. They might bring that number up to 600. I think I'm going to add a couple more dynos tonight, for peace of mind. I only pay by the hour, so that peace of mind will cost $2.50. Worthwhile I would say.

Hm.. I went to the logs to see if I could see my new dynos at work, but I don't see them. I still see references to web.1 and web.2, but no web.3 or web.4... oh.. Logentries doesn't populate the whole list of log entries, I need to keep scrolling to the bottom before it fetches more. Ok, I see web.3 and web.4. Horray.

all the dynos are working so hard. they're so cute. serving requests.. and such.. please don't get overwhelmed dynos!

on to bed.

puff, e-mail, todo

I suppose I need to face the giant, rather than complain.

I just feel like I could have done something in the past to have prevented being here.. or figured out some strategy to make it easier..

I guess when I'm faced with a lot of grunge work, I always think, is there something clever I can do to kill all these birds with one well crafted stone?

I could delete my e-mail and todo lists. Things would probably be ok. But somehow I want a more graceful solution.. but I definitely want to tend toward not having a giant backlog of stuff that I feel is important and urgent.