Ubuntu
dovecot package

Initial USER command returns -ERR Unkown command

Bug #66863 reported by Russell Smith on 2006-10-19

Affects		Status	Importance	Assigned to	Milestone
	dovecot (Ubuntu)	Invalid	Undecided	Russell Smith

Bug Description

Starting a telnet session to dovecot

+OK Dovecot ready.
user <email address hidden>
-ERR Unknown command.
user <email address hidden>
+OK
pass *******
+OK Logged in.
LIST
+OK 0 messages:
.
QUIT

Notice how the first instance of user reports that there is no command user.
I am running 6.06 dapper all patches to dovecot applied. 1.0.beta3-3ubuntu5

Revision history for this message

Russell Smith (mr-russ) wrote on 2006-10-19:

Download full text (14.0 KiB)

Example strace of login procedure.

850   gettimeofday({1161233890, 75122}, {4294966696, 0}) = 0
850   gettimeofday({1161233890, 75217}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 445) = 0
850   gettimeofday({1161233890, 531827}, {4294966696, 0}) = 0
850   gettimeofday({1161233890, 531891}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233890, 532028}, {4294966696, 0}) = 0
850   gettimeofday({1161233890, 532098}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233891, 541849}, {4294966696, 0}) = 0
850   gettimeofday({1161233891, 541915}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233891, 542054}, {4294966696, 0}) = 0
850   gettimeofday({1161233891, 542124}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233892, 551853}, {4294966696, 0}) = 0
850   gettimeofday({1161233892, 551920}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233892, 552061}, {4294966696, 0}) = 0
850   gettimeofday({1161233892, 552135}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233893, 561839}, {4294966696, 0}) = 0
850   gettimeofday({1161233893, 561906}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233893, 562046}, {4294966696, 0}) = 0
850   gettimeofday({1161233893, 562116}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233894, 571829}, {4294966696, 0}) = 0
850   gettimeofday({1161233894, 571897}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233894, 572038}, {4294966696, 0}) = 0
850   gettimeofday({1161233894, 572111}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233895, 581804}, {4294966696, 0}) = 0
850   gettimeofday({1161233895, 581870}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233895, 582089}, {4294966696, 0}) = 0
850   gettimeofday({1161233895, 582159}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 999) = 1
850   gettimeofday({1161233896, 74911}, {4294966696, 0}) = 0
850   read(9, "user hugh@stubley.net", 4075) = 21
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233896, 75246}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 506) = 1
850   gettimeofday({1161233896, 77862}, {4294966696, 0}) = 0
850   read(9, "\r\n", 4054)             = 2
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   write(9, "-ERR Unknown command.\r\n", 23) = 23
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233896, 78264}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 503) = 0
850   gettimeofday({1161233896, 591748}, {4294966696, 0}) = 0
850   gettimeofday({1161233896, 591813}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233896, 591952}, {4294966696, 0}) = 0
850   gettimeofday({1161233896, 592023}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 998) = 0
850   gettimeofday({1161233897, 602188}, {4294966696, 0}) = 0
850   gettimeofday({1161233897, 602258}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233897, 602401}, {4294966696, 0}) = 0
850   gettimeofday({1161233897, 602478}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233898, 611738}, {4294966696, 0}) = 0
850   gettimeofday({1161233898, 611806}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233898, 611948}, {4294966696, 0}) = 0
850   gettimeofday({1161233898, 612022}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 998) = 0
850   gettimeofday({1161233899, 621708}, {4294966696, 0}) = 0
850   gettimeofday({1161233899, 621774}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233899, 621994}, {4294966696, 0}) = 0
850   gettimeofday({1161233899, 622066}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 998) = 1
850   gettimeofday({1161233900, 546289}, {4294966696, 0}) = 0
850   read(9, "user hugh@stubley.net", 4052) = 21
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233900, 546583}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 74) = 1
850   gettimeofday({1161233900, 548450}, {4294966696, 0}) = 0
850   read(9, "\r\n", 4031)             = 2
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   write(9, "+OK\r\n", 5)            = 5
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233900, 548811}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 72) = 0
850   gettimeofday({1161233900, 631606}, {4294966696, 0}) = 0
850   gettimeofday({1161233900, 631669}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233900, 631806}, {4294966696, 0}) = 0
850   gettimeofday({1161233900, 631876}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233901, 641705}, {4294966696, 0}) = 0
850   gettimeofday({1161233901, 641772}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233901, 641913}, {4294966696, 0}) = 0
850   gettimeofday({1161233901, 641985}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 999) = 0
850   gettimeofday({1161233902, 651723}, {4294966696, 0}) = 0
850   gettimeofday({1161233902, 651790}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 4, 0) = 0
850   gettimeofday({1161233902, 651928}, {4294966696, 0}) = 0
850   gettimeofday({1161233902, 651999}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 999) = 1
850   gettimeofday({1161233902, 790479}, {4294966696, 0}) = 0
850   read(9, "pass ********", 4029)    = 13
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233902, 790764}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=9, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 4, 860) = 1
850   gettimeofday({1161233902, 792972}, {4294966696, 0}) = 0
850   read(9, "\r\n", 4016)             = 2
850   setsockopt(9, SOL_TCP, TCP_CORK, [1], 4) = 0
850   write(10, "AUTH\t1\tPLAIN\tservice=POP3\tlip=20"..., 105) = 105
850   setsockopt(9, SOL_TCP, TCP_CORK, [0], 4) = 0
850   gettimeofday({1161233902, 793396}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 3, 857) = 1
850   gettimeofday({1161233902, 795481}, {4294966696, 0}) = 0
850   read(10, "OK\t1\tuser=hugh@stubley.net\t\n", 4041) = 28
850   sendmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"\1\0\0\0\1\0\0\0\373\2\0\0\1\0\0\0\2\0\5\10\312\206&cJ"..., 56}], msg_controllen=16, {cmsg_len=16, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, {9}}, msg_flags=0}, 0) = 56
850   gettimeofday({1161233902, 795934}, NULL) = 0
850   poll([{fd=7, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=10, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=3, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 3, 855) = 1
850   gettimeofday({1161233902, 801507}, {4294966696, 0}) = 0
850   read(3, "\1\0\0\0\1\0\0\0", 8)    = 8
850   writev(9, [{"+OK Logged in.", 14}, {"\r\n", 2}], 2) = 16
850   write(2, "\1ILogin: user=<hugh@stubley.net>"..., 86) = 86
850   close(9)                          = 0
850   close(3)                          = 0
850   close(10)                         = 0
850   close(7)                          = 0
850   close(8)                          = 0
850   rt_sigaction(SIGRT_2, {SIG_IGN}, {0x8054d10, [], SA_RESTART|SA_NOMASK|SA_SIGINFO}, 8) = 0
850   close(5)                          = 0
850   close(6)                          = 0
850   exit_group(0)                     = ?

Revision history for this message

Russell Smith (mr-russ) wrote on 2006-10-22:

A full stop and start of the server solved the problem. As I'm unable to determine what setting I changed to cause this error to begin with, I'm closing the bug.

The bug in the future would be that restart is not equivilent to stop and start.

Changed in dovecot:
assignee:	nobody → mr-russ
status:	Unconfirmed → Rejected

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.

Ubuntudovecot package

Initial USER command returns -ERR Unkown command

Bug Description

Other bug subscribers

Remote bug watches

Ubuntu
dovecot package