diff -r 941608f8b3fb src/lib-mail/istream-header-filter.c --- a/src/lib-mail/istream-header-filter.c Tue Jun 01 16:01:21 2010 +0100 +++ b/src/lib-mail/istream-header-filter.c Tue Jun 01 16:07:48 2010 +0100 @@ -63,6 +63,7 @@ return -1; } + i_debug("%p: hdr-filter read mixed", &mstream->istream.istream); data = i_stream_get_data(mstream->istream.parent, &pos); if (pos == body_highwater_size) { ret = i_stream_read(mstream->istream.parent); @@ -282,6 +283,7 @@ if (!mstream->header_read || stream->istream.v_offset < mstream->header_size.virtual_size) { + i_debug("%p: hdr-filter read header offset=%lu", &stream->istream, (long)stream->istream.v_offset); ret = read_header(mstream); if (ret != -2 || stream->pos != stream->skip) return ret; @@ -295,6 +297,7 @@ v_offset = stream->parent_start_offset + stream->istream.v_offset - mstream->header_size.virtual_size + mstream->header_size.physical_size; + i_debug("%p: hdr-filter read body at %lu", &stream->istream, (long)v_offset); i_stream_seek(stream->parent, v_offset); return i_stream_read_copy_from_parent(&stream->istream); } @@ -303,6 +306,7 @@ i_stream_header_filter_seek_to_header(struct header_filter_istream *mstream, uoff_t v_offset) { + i_debug("%p: hdr-filter seek-to-header", &mstream->istream.istream); i_stream_seek(mstream->istream.parent, mstream->istream.parent_start_offset); mstream->istream.parent_expected_offset = @@ -328,9 +332,11 @@ if (mstream->istream.access_counter != mstream->istream.parent->real_stream->access_counter) { /* need to re-parse headers */ + i_debug("%p: hdr-filter access reset", &mstream->istream.istream); i_stream_header_filter_seek_to_header(mstream, 0); } + i_debug("hdr-filter skip header"); while (!mstream->header_read && i_stream_read(&mstream->istream.istream) != -1) { (void)i_stream_get_data(&mstream->istream.istream, &pos); @@ -353,6 +359,7 @@ struct header_filter_istream *mstream = (struct header_filter_istream *)stream; + i_debug("%p: hdr-filter seek %lu to %lu", &stream->istream, (long)stream->istream.v_offset, (long)v_offset); if (stream->istream.v_offset == v_offset) { /* just reset the input buffer */ stream_reset_to(mstream, v_offset); @@ -360,11 +367,11 @@ mstream->istream.parent_expected_offset); return; } - if (v_offset == 0) { /* seeking to beginning of headers. */ stream_reset_to(mstream, 0); i_stream_header_filter_seek_to_header(mstream, 0); + i_debug("%p: hdr-filter /seek", &stream->istream); return; } @@ -385,6 +392,7 @@ i_stream_seek(stream->parent, stream->parent_start_offset + v_offset); } + i_debug("%p: hdr-filter /seek", &stream->istream); } static void ATTR_NORETURN @@ -401,6 +409,7 @@ const struct stat *st; uoff_t old_offset; + i_debug("%p: hdr-filter stat", &stream->istream); st = i_stream_stat(stream->parent, exact); if (st == NULL || st->st_size == -1 || !exact) return st; diff -r 941608f8b3fb src/lib/istream-file.c --- a/src/lib/istream-file.c Tue Jun 01 16:01:21 2010 +0100 +++ b/src/lib/istream-file.c Tue Jun 01 16:07:48 2010 +0100 @@ -106,7 +106,7 @@ if (!stream->istream.seekable) { if (v_offset < stream->istream.v_offset) - i_panic("stream doesn't support seeking backwards"); + i_panic("%p: stream doesn't support seeking backwards", &stream->istream); fstream->skip_left += v_offset - stream->istream.v_offset; } @@ -165,5 +165,6 @@ } fstream->istream.istream.readable_fd = TRUE; + i_debug("%p: create file", fstream); return i_stream_create(&fstream->istream, NULL, fd); } diff -r 941608f8b3fb src/lib/istream-limit.c --- a/src/lib/istream-limit.c Tue Jun 01 16:01:21 2010 +0100 +++ b/src/lib/istream-limit.c Tue Jun 01 16:07:48 2010 +0100 @@ -37,6 +37,8 @@ return -1; } + i_debug("%p: limit read, seeking parent=%p to=%lu", &stream->istream, stream->parent, + (long)(lstream->istream.parent_start_offset + stream->istream.v_offset)); i_stream_seek(stream->parent, lstream->istream.parent_start_offset + stream->istream.v_offset); diff -r 941608f8b3fb src/lib/istream-tee.c --- a/src/lib/istream-tee.c Tue Jun 01 16:01:21 2010 +0100 +++ b/src/lib/istream-tee.c Tue Jun 01 16:07:48 2010 +0100 @@ -219,6 +219,7 @@ tstream->next = tee->children; tee->children = tstream; + i_debug("%p: create tee child", tstream); ret = i_stream_create(&tstream->istream, input, i_stream_get_fd(input)); /* we keep the reference in tee stream, no need for extra references */ i_stream_unref(&input); diff -r 941608f8b3fb src/lib/istream.c --- a/src/lib/istream.c Tue Jun 01 16:01:21 2010 +0100 +++ b/src/lib/istream.c Tue Jun 01 16:07:48 2010 +0100 @@ -9,6 +9,7 @@ { i_free(stream->real_stream->iostream.name); stream->real_stream->iostream.name = i_strdup(name); + i_debug("%p: name=%s", stream, name); } const char *i_stream_get_name(struct istream *stream) @@ -37,6 +38,7 @@ struct istream_private *_stream = (*stream)->real_stream; if (_stream->iostream.refcount == 1) { + i_debug("%p: freed", stream); if (_stream->line_str != NULL) str_free(&_stream->line_str); } @@ -108,11 +110,16 @@ stream->eof = FALSE; stream->stream_errno = 0; - if (_stream->parent != NULL) + i_debug("%p: read offset=%"PRIuUOFF_T, stream, stream->v_offset); + if (_stream->parent != NULL) { + i_debug("%p: seeking parent=%p offset=%"PRIuUOFF_T, stream, + _stream->parent, _stream->parent_expected_offset); i_stream_seek(_stream->parent, _stream->parent_expected_offset); + } old_size = _stream->pos - _stream->skip; ret = _stream->read(_stream); + i_debug("%p: read ret=%d", stream, (int)ret); switch (ret) { case -2: i_assert(_stream->skip != _stream->pos); @@ -179,11 +186,20 @@ data_size = _stream->pos - _stream->skip; if (count <= data_size) { /* within buffer */ + i_debug("%p: skip: %lu + %u = %lu", stream, + (long)stream->v_offset, (int)count, + (long)(stream->v_offset + count)); + stream->v_offset += count; _stream->skip += count; return; } + i_debug("%p: skip seeks: %lu + %u = %lu (count=%u <= data_size=%u (skip=%u pos=%u))", stream, + (long)stream->v_offset, (int)count, + (long)(stream->v_offset + count), (int)count, (int)data_size, + (int)_stream->skip, (int)_stream->pos); + /* have to seek forward */ count -= data_size; _stream->skip = _stream->pos; @@ -214,12 +230,16 @@ struct istream_private *_stream = stream->real_stream; if (v_offset >= stream->v_offset && - i_stream_can_optimize_seek(_stream)) + i_stream_can_optimize_seek(_stream)) { + i_debug("%p: seek: %lu -> skip %u = %lu", stream, + (long)stream->v_offset, (int)(v_offset - stream->v_offset), + (long)v_offset); i_stream_skip(stream, v_offset - stream->v_offset); - else { + } else { if (unlikely(stream->closed)) return; + i_debug("%p: seek: %lu -> seek to %"PRIuUOFF_T, stream, (long)stream->v_offset, v_offset); stream->eof = FALSE; _stream->seek(_stream, v_offset, FALSE); } @@ -536,7 +556,7 @@ size_t available; if (stream->istream.v_offset > v_offset) - i_panic("stream doesn't support seeking backwards"); + i_panic("%p: stream doesn't support seeking backwards", &stream->istream); while (stream->istream.v_offset < v_offset) { (void)i_stream_read(&stream->istream); @@ -581,6 +601,8 @@ { _stream->fd = fd; if (parent != NULL) { + i_debug("%p: created parent=%p name=%s", + &_stream->istream, parent, i_stream_get_name(parent)); _stream->access_counter = parent->real_stream->access_counter; _stream->parent = parent; _stream->parent_start_offset = parent->v_offset; @@ -588,6 +610,8 @@ _stream->abs_start_offset = parent->v_offset + parent->real_stream->abs_start_offset; i_stream_ref(parent); + } else { + i_debug("%p: created parent=NULL", &_stream->istream); } _stream->istream.real_stream = _stream;