DEBUG: Error: Message underflow.

[craftgear]

This may not be an issue of parted.

At first, I posted this problem at Zombie repository But I am at a loss where to go. So I'm here to seek help.

Here's a story. I test my application (which is based on express) with zombie for functional tests.

When I tested file upload function, I got weird error.

• zombie + formidable = error
• zombie + parted = error (which is shown below)
• Firefox7 + formidable = ok
• Firefox7 + parted = ok

I guessed zimbie had some bugs at this point. But,

• zombie + strata (which adopted formidable codes) = ok
• zombie + php = ok

Hmm, zombie works well other servers. Then I guessed any problems lurked somewhere in express.

I traced codes of express, and of course them of parted. But I couldn't find anything.

Do you guys have any guesses? I appreciate any clues.

Thanks.

DEBUG: Error: Message underflow.
    at [object Object]._error (/home/user/.nave/installed/0.4.12/lib/node_modules/parted/lib/multipart.js:315:7)
    at [object Object].end (/home/user/.nave/installed/0.4.12/lib/node_modules/parted/lib/multipart.js:87:17)
    at IncomingMessage.onend (stream.js:74:10)
    at IncomingMessage.emit (events.js:81:20)
    at HTTPParser.onMessageComplete (http.js:133:23)
    at Socket.ondata (http.js:1029:22)
    at Socket._onReadable (net.js:677:27)
    at IOWatcher.onReadable [as callback] (net.js:177:10)

[chjj]

A message underflow is thrown when the message ends but the last boundary hasn't been fully parsed, or been parsed at all. Either the integrity of the message was actually compromised when uploading, or zombie doesn't send the trailing "--", which is required by the specification for the last boundary. (It could also be the case that zombie is not sending a final boundary key at all).

Something could be wrong with the multipart parser, but since the bug occurred in both formidable and parted (and they gave the same exact kind of error), I'm guessing it has something to do with zombie.

I wouldn't want to fix this for the sake of zombie because it's actually a very important integrity check.

[chjj]

If you could show me a gist of the exact multipart message (headers included) that zombie is producing, I might be able to see if something is wrong. The raw output would be good, minus the binary data.

[craftgear]

THANK-YOU-SO-MUCH!

I think I'll find way to go. I'm gonna dig into zombie codes and report back.

Regard for integrity thing, I totally agree with you.

Now it's time to dissect corps.

[craftgear]

I found zombie said server bigger header["content-length"] than actual body size due to including boundary texts and so on. So, I change the code to match header["content-length"] to total body length, and Voila! I got a new error!

error: Loading resource: socket hang up - More:
Error: socket hang up

Here's a output of request.toString() of zombie.

{ referer: 'http://localhost:3000/post/new',
  'User-Agent': 'Zombie',
  Host: 'localhost:3000',
  cookie: 'connect.sid=UeWaIpFyMVmjn92cvb48fkig.67LinxPga%2FhaLztcUodW3cyO5WhuSabH%2BlQLgXJcqbI' }

{ 'content-type': 'multipart/form-data; boundary=13201255496610.29800816415809095',
  referer: 'http://localhost:3000/post/new',
  'User-Agent': 'Zombie',
  'Content-Length': 34,
  Host: 'localhost:3000',
  cookie: 'connect.sid=UeWaIpFyMVmjn92cvb48fkig.67LinxPga%2FhaLztcUodW3cyO5WhuSabH%2BlQLgXJcqbI' }
--13201255496610.29800816415809095
Content-Disposition: form-data; name="id"
Content-Type: application/octet-stream
Content-Length: 24

4eaf846dafb34dc532000006
--13201255496610.29800816415809095
Content-Disposition: form-data; name="body"
Content-Type: application/octet-stream
Content-Length: 5

abcde
--13201255496610.29800816415809095
Content-Disposition: form-data; name="new_tag"
Content-Type: application/octet-stream
Content-Length: 5

nnnnn
--13201255496610.29800816415809095--

As you see, this request doesn't include file data, tough a form has a file field and "enctype='multipart/form-data'". Because of I left a file field blank.

Any wild guesses? Thanks.

[chjj]

I can't see anything wrong with it.

It looks fine unless it's doing something like using just line feeds instead of CRLF. I can't tell if it is or not because github probably normalizes them. The problem might lie in the headers, not the headers for each part, but the raw header for the entire message. Taking a look at them without getting parsed as JSON might help.

[chjj]

I've also been looking at the code for zombie's multipart submission: https://github.com/assaf/zombie/blob/master/src/zombie/resources.coffee

From what I can tell right now, the code seems to be correct. I'll have to mess around with zombie a bit to figure it out.

[craftgear]

Thanks again, chjj.

Actually in resources.coffee, line.220 bloats header['content-length'] unnecessary. It causes former 'Message underflow' error.

And about row headers, I couldn't catch it in javascript . Maybe should I use WireShark or something?

Regards.

[craftgear]

I managed to get raw post data.

POST /post/create HTTP/1.1\r\n
content-type: multipart/form-data; boundary=13203167654900.07227878388948739\r\n
referer: http://localhost:3000/post/new\r\n
User-Agent: Zombie\r\n
content-length: 34\r\n
Host: localhost:3000\r\n
cookie: connect.sid=IePKJvENTtRtqfQdu8V6dD2I.vH4kNeo7oCUVSYrW4I8faUXj38%2FHLIdWdUbQ9ZaPiO4\r\n
Connection: close\r\n
\r\n
--13203167654900.07227878388948739\r\n
Content-Disposition: form-data; name="id"\r\n
Content-Type: text/plain\r\n
Content-Length: 24\r\n
\r\n
4eb26f5dd8edfd2408000010\r\n
--13203167654900.07227878388948739\r\n
Content-Disposition: form-data; name="body"\r\n
Content-Type: text/plain\r\n
Content-Length: 5\r\n
\r\n
abcde\r\n
--13203167654900.07227878388948739\r\n
Content-Disposition: form-data; name="new_tag"\r\n
Content-Type: text/plain\r\n
Content-Length: 5\r\n
\r\n
nnnnn\r\n
--13203167654900.07227878388948739--\r\n

I noticed that "Connection: close\r\n" was sent after cookie. I don't found such a line in LiveHttpHeader extension log on Firefox. Is this valid?

[chjj]

Maybe it's a problem with the http client closing the connection to soon? If no agent is used, connection:close is set and node calls .destroySoon on the socket. Maybe try sending the request using an agent and see if there is a difference?

Or, instead of using parted, just look at the raw data recieved by the server, and see if it is complete?

It would make sense if the socket was getting prematurely closed for some strange reason, as both parted and formidable are saying it is.

[craftgear]

Hi, chjj. I have some progress.

I could circumvent a "Message underflow" error and uploaded a file by not sending headers['content-length']. But I noticed an uploaded file remained base64 encoded strings.

And I also noticed zombie against a php file upload script yielded the same result.

I'm going to post this new problem on zombie repository.

Thanks for your help.

[chjj]

Zombie uses base64 for it's file uploads? Why? The parted multipart parser doesn't take into account base64'd files right now. Maybe I should implement it now that I see something actually uses it. I've never seen a browser use it though. There doesn't seem to be much reason to use it, as http can handle raw binary.

Anyway, interesting, hope you get it sorted out.

[craftgear]

Hi, chjj. Here's a sequel.

I managed to make zombie send binary files as binary. It worked well with parted and formidable. At the same time, It broke bunch of specs of zombie because of #3 below.

Here are what I could know as of now.

1. Zombie sends binary files as base64 encoded strings as I have already mentioned.
2. Parted and formidable don't suppose to work with base64 encoded files.
3. A file upload spec of zombie is extends connect.bodyParser and implements its own multipart-parser.
4. Connect.bodyParser always handles a request body as UTF8 encoded, so binary request bodies are broken.

Now I'm thinking to abandon zombie and move to soda & selenium for functional testing. And again, thanks for your support on this matter.