gsasl stops working in Fedora 16

[Enrico Scholz]

Hi,

after upgrading to fedora 16 I noticed that the gsasl tool (which is
used to connect to an IMAP server) does not work as expected anymore.
When receiving a multiline message, it does not flush the last line.

E.g.

| $ gsasl mailbox.... 143 --imap --mechanism GSSAPI --authentication-id ensc
| ...
| * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT 
SORT=DISPLAY THREAD=REFERENCES THREAD=REFS MULTIAPPEND UNSELECT CHILDREN 
NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT 
SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS
| Client authentication finished (server trusted)...
| Enter application data (EOF to finish):
| 
| <<< pressing ENTER here
| 
| . OK Logged in
| * BAD Error in IMAP command : Unknown command.

The 'OK Logged in' response was printed with fedora 15 before I had to
press ENTER.

strace shows

| 10:28:57 write(1, "* CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID 
ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS MULTIAPPEND 
UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC 
ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS\r\n", 270* CAPABILITY 
IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY 
THREAD=REFERENCES THREAD=REFS MULTIAPPEND UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS
| ) = 270
| 10:28:57 poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}], 2, -1
| ) = 1 ([{fd=0, revents=POLLIN}])
| 
| <<< pressing ENTER here
| 
| 10:29:00 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 14), ...}) = 0
| 10:29:00 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0x7f198b62f000
| 10:29:00 read(0, "\n", 1024)            = 1
| 10:29:00 getrusage(RUSAGE_SELF, {ru_utime={0, 19996}, ru_stime={0, 14997}, 
...}) = 0
| 10:29:00 times({tms_utime=1, tms_stime=1, tms_cutime=0, tms_cstime=0}) = 
432149803
| 10:29:00 getrusage(RUSAGE_SELF, {ru_utime={0, 19996}, ru_stime={0, 14997}, 
...}) = 0
| 10:29:00 times({tms_utime=1, tms_stime=1, tms_cutime=0, tms_cstime=0}) = 
432149803
| 10:29:00 writev(3, 
[{"\27\3\1\0000\372\322x\37E\f\201l\203\266\262\35)4\271\276\272\340\10\330\4\236n\6\311C\3067-9\323\270\234\251gzf\221a\336\222\322\353>_\233\222w",
 53}], 1) = 53
| 10:29:00 poll([{fd=0, events=POLLIN}, {fd=3, events=POLLIN}], 2, -1) = 1 
([{fd=3, revents=POLLIN}])
| 10:29:00 write(1, ". OK Logged in\r\n", 16. OK Logged in
| ) = 16

This shows that no data was received over the network after ENTER and
that the 'OK Logged in' was available before ENTER was pressed.


ltrace show

| 10:13:00 gnutls_record_recv(0x1890330, 0x189b81d, 1, 0x1895c0d, 1)            
 = 1
| 10:13:00 __printf_chk(1, 0x409e05, 0x189b710, 0x1895c0e, 1* CAPABILITY 
IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY 
THREAD=REFERENCES THREAD=REFS MULTIAPPEND UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS
| )                    = 270
| 10:13:00 poll(0x7fffa0f0f260, 2, 0xffffffff, 0, 0x409e07
| )                      = 1
| 
| <<< pressing ENTER here
| 
| 10:13:03 __getdelim(0x7fffa0f0f2c8, 0x7fffa0f0f2d0, 10, 0x7f67e39b5320, 
0x409e07) = 1
| 10:13:03 realloc(0x0189a9e0, 3)                                               
 = 0x0189a9e0
| 10:13:03 gsasl_encode(0x18910c0, 0x189a9e0, 2, 0x7fffa0f0f298, 
0x7fffa0f0f2a8) = 0
| 10:13:03 gnutls_record_send(0x1890330, 0x1886940, 2, 238, 2)                  
 = 2
| 10:13:03 free(0x0189a9e0)                                                     
 = <void>
| 10:13:03 free(0x01886940)                                                     
 = <void>
| 10:13:03 poll(0x7fffa0f0f260, 2, 0xffffffff, 0x7f67e39b4708, 16)              
 = 1
| 10:13:03 realloc(NULL, 1000)                                                  
 = 0x0189b860
| 10:13:03 gnutls_record_recv(0x1890330, 0x189b860, 1000, 554, 104)             
 = 16
| 10:13:03 gsasl_decode(0x18910c0, 0x189b860, 16, 0x7fffa0f0f298, 
0x7fffa0f0f2a8) = 0
| 10:13:03 free(0x0189b860)                                                     
 = <void>
| 10:13:03 __printf_chk(1, 0x409d4d, 16, 0x1886940, 96. OK Logged in
| )                          = 16
| 10:13:03 free(0x01886940)                                                     
 = <void>


I will investigate it further, but perhaps somebody has an idea what is
going on here?




Enrico