Re[3]: [exim] Debugging 'Invalid base64 data"

Top Page
Delete this message
Reply to this message
Author: Felix Brack
Date:  
To: exim-users
Subject: Re[3]: [exim] Debugging 'Invalid base64 data"
My intial problem is resolved: it was _not_ an exim problem, it was a
problem with the client, sorry.

But...
I fully agree with you, it looks odd and that is a problem. The following
logs show a client with which sending mail works. The log remains odd
(even if the entiere communication with exim is ok) since only parts of
the SMTP dialog appear. Exim was started with -d+all.

A little help to read the logs:

what                        base64 encoded        decoded
---------------------------------------------------------------
the literal "Username:"     VXNlcm5hbWU6          Username:
the literal "Password:"     UGFzc3dvcmQ6          Password:
the user name to log in     ZmJAbHRlYy5jaA==      fb@???


I did overwrite the password (which _is_ correct) with ******.

This is the debug dump of exim started with -d+all. As I already
stated the dump shows "Username:" and "Password:" which are sent as
prompts from exim to the client but the answers from the client are
not logged. The user name would be "fb@???" and the password
"******". I would have expected to find them in the log.
(See below for the corresponding log of tcpdump)

------------------ exim log starts here ------------------------
19:25:47 13506 SMTP>> 220 JUPITER.ltec ESMTP Exim 4.60 Thu, 02 Mar 2006 19:25:47 +0100
19:25:47 13506 Process 13506 is ready for new message
19:25:47 13506 smtp_setup_msg entered
19:25:48 13506 SMTP<< EHLO [62.202.253.187]
19:25:48 13506 sender_fullhost = 187.253.202.62.cust.bluewin.ch [62.202.253.187]
19:25:48 13506 sender_rcvhost = 187.253.202.62.cust.bluewin.ch ([62.202.253.187])
19:25:48 13506 set_process_info: 13506 handling incoming connection from 187.253.202.62.cust.bluewin.ch [62.202.253.187]
19:25:48 13506 host in pipelining_advertise_hosts? yes (matched "*")
19:25:48 13506 host in auth_advertise_hosts? yes (matched "*")
19:25:48 13506 host in tls_advertise_hosts? no (option unset)
19:25:48 13506 SMTP>> 250-JUPITER.ltec Hello 187.253.202.62.cust.bluewin.ch [62.202.253.187]
19:25:48 13506 250-SIZE 52428800
19:25:48 13506 250-PIPELINING
19:25:48 13506 250-AUTH CRAM-MD5 PLAIN LOGIN
19:25:48 13506 250 HELP
19:25:49 13506 SMTP<< AUTH LOGIN
19:25:49 13506 SMTP>> 334 VXNlcm5hbWU6
19:25:50 13506 SMTP>> 334 UGFzc3dvcmQ6
19:25:50 13506 expanding: $1
19:25:50 13506    result: fb@???
19:25:50 13506 expanding: /usr/local/exim/auth.passwd
19:25:50 13506    result: /usr/local/exim/auth.passwd
19:25:50 13506 search_open: lsearch "/usr/local/exim/auth.passwd"
19:25:50 13506 search_find: file="/usr/local/exim/auth.passwd"
19:25:50 13506   key="fb@???" partial=-1 affix=NULL starflags=0
19:25:50 13506 LRU list:
19:25:50 13506   :/usr/local/exim/auth.passwd
19:25:50 13506   End
19:25:50 13506 internal_search_find: file="/usr/local/exim/auth.passwd"
19:25:50 13506   type=lsearch key="fb@???"
19:25:50 13506 file lookup required for fb@???
19:25:50 13506   in /usr/local/exim/auth.passwd
19:25:50 13506 lookup yielded: ******
19:25:50 13506 expanding: $value
19:25:50 13506    result: ******
19:25:50 13506 expanding: $2
19:25:50 13506    result: ******
19:25:50 13506 condition: eq{$value}{$2}
19:25:50 13506    result: true
19:25:50 13506 expanding: yes
19:25:50 13506    result: yes
19:25:50 13506 expanding: no
19:25:50 13506    result: no
19:25:50 13506 skipping: result is not used
19:25:50 13506 expanding: ${if eq{$value}{$2}{yes}{no}}
19:25:50 13506    result: yes
19:25:50 13506 expanding: no
19:25:50 13506    result: no
19:25:50 13506 skipping: result is not used
19:25:50 13506 expanding: ${lookup{$1}lsearch{/usr/local/exim/auth.passwd}{${if eq{$value}{$2}{yes}{no}}}{no}}
19:25:50 13506    result: yes
19:25:50 13506 lookup_login authenticator:
19:25:50 13506   $1 = fb@???
19:25:50 13506   $2 = ******
19:25:50 13506 expanded string: yes
19:25:50 13506 expanding: $1
19:25:50 13506    result: fb@???
19:25:50 13506 SMTP>> 235 Authentication succeeded
19:25:52 13506 SMTP<< RSET
19:25:52 13506 SMTP>> 250 Reset OK
19:25:53 13506 SMTP<< MAIL FROM:<fb@???>
19:25:53 13506 SMTP>> 250 OK
19:25:53 13506 SMTP<< RCPT TO:<ltec@???>
------------------ exim log ends here ------------------------


Following is the log of tcpdump. This one shows the entire SMTP dialog
for the corresponding sequence, _including_ the answers from the
client which are the username "fb@???" (ZmJAbHRlYy5jaA==) and the
password (again just ******).

------------------ tcpdump log starts here ------------------------
19:25:48.539380 212.98.40.148.25 > 62.202.253.187.3365: P 67:215(148) ack 24 win 5800 (DF)
0x0000   4500 00bc 608b 4000 4006 a034 d462 2894        E...`.@.@..4.b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e5f3 2513 ee98        >......%....%...
0x0020   5018 16a8 88c9 0000 3235 302d 4a55 5049        P.......250-JUPI
0x0030   5445 522e 6c74 6563 2048 656c 6c6f 2031        TER.ltec.Hello.1
0x0040   3837 2e32 3533 2e32 3032 2e36 322e 6375        87.253.202.62.cu
0x0050   7374 2e62 6c75 6577 696e 2e63 6820 5b36        st.bluewin.ch.[6
0x0060   322e 3230 322e 3235 332e 3138 375d 0d0a        2.202.253.187]..
0x0070   3235 302d 5349 5a45 2035 3234 3238 3830        250-SIZE.5242880
0x0080   300d 0a32 3530 2d50 4950 454c 494e 494e        0..250-PIPELININ
0x0090   470d 0a32 3530 2d41 5554 4820 4352 414d        G..250-AUTH.CRAM
0x00a0   2d4d 4435 2050 4c41 494e 204c 4f47 494e        -MD5.PLAIN.LOGIN
0x00b0   0d0a 3235 3020 4845 4c50 0d0a                  ..250.HELP..
19:25:49.221815 62.202.253.187.3365 > 212.98.40.148.25: P 24:36(12) ack 215 win 8192
0x0000   4500 0034 0007 0000 f806 8940 3eca fdbb        E..4.......@>...
0x0010   d462 2894 0d25 0019 2513 ee98 f7b1 e687        .b(..%..%.......
0x0020   5018 2000 fb96 0000 4155 5448 204c 4f47        P.......AUTH.LOG
0x0030   494e 0d0a                                      IN..
19:25:49.222579 212.98.40.148.25 > 62.202.253.187.3365: P 215:233(18) ack 36 win 5800 (DF)
0x0000   4500 003a 608c 4000 4006 a0b5 d462 2894        E..:`.@.@....b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e687 2513 eea4        >......%....%...
0x0020   5018 16a8 f6e0 0000 3333 3420 5658 4e6c        P.......334.VXNl
0x0030   636d 3568 6257 5536 0d0a                       cm5hbWU6..
19:25:49.941683 62.202.253.187.3365 > 212.98.40.148.25: . ack 233 win 8192
0x0000   4500 0028 0008 0000 f806 894b 3eca fdbb        E..(.......K>...
0x0010   d462 2894 0d25 0019 2513 eea4 f7b1 e699        .b(..%..%.......
0x0020   5010 2000 5716 0000                            P...W...
19:25:50.046455 62.202.253.187.3365 > 212.98.40.148.25: P 36:54(18) ack 233 win 8192
0x0000   4500 003a 0009 0000 f806 8938 3eca fdbb        E..:.......8>...
0x0010   d462 2894 0d25 0019 2513 eea4 f7b1 e699        .b(..%..%.......
0x0020   5018 2000 c32c 0000 5a6d 4a41 6248 526c        P....,..ZmJAbHRl
0x0030   5979 356a 6141 3d3d 0d0a                       Yy5jaA==..
19:25:50.047327 212.98.40.148.25 > 62.202.253.187.3365: P 233:251(18) ack 54 win 5800 (DF)
0x0000   4500 003a 608d 4000 4006 a0b4 d462 2894        E..:`.@.@....b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e699 2513 eeb6        >......%....%...
0x0020   5018 16a8 d3d5 0000 3333 3420 5547 467a        P.......334.UGFz
0x0030   6333 6476 636d 5136 0d0a                       c3dvcmQ6..
19:25:50.756685 62.202.253.187.3365 > 212.98.40.148.25: P 54:68(14) ack 251 win 8192
0x0000   4500 0036 000a 0000 f806 893b 3eca fdbb        E..6.......;>...
0x0010   d462 2894 0d25 0019 2513 eeb6 f7b1 e6ab        .b(..%..%.......
0x0020   5018 2000 6570 0000 5a6d 4a58 516e 5679        P...ep..********
0x0030   5a77 3d3d 0d0a                                 ****..
19:25:50.761040 212.98.40.148.25 > 62.202.253.187.3365: P 251:281(30) ack 68 win 5800 (DF)
0x0000   4500 0046 608e 4000 4006 a0a7 d462 2894        E..F`.@.@....b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e6ab 2513 eec4        >......%....%...
0x0020   5018 16a8 50c5 0000 3233 3520 4175 7468        P...P...235.Auth
0x0030   656e 7469 6361 7469 6f6e 2073 7563 6365        entication.succe
0x0040   6564 6564 0d0a                                 eded..
19:25:51.541700 62.202.253.187.3365 > 212.98.40.148.25: . ack 281 win 8192
0x0000   4500 0028 000b 0000 f806 8948 3eca fdbb        E..(.......H>...
0x0010   d462 2894 0d25 0019 2513 eec4 f7b1 e6c9        .b(..%..%.......
0x0020   5010 2000 56c6 0000                            P...V...
19:25:52.348325 62.202.253.187.3365 > 212.98.40.148.25: P 68:74(6) ack 281 win 8192
0x0000   4500 002e 000c 0000 f806 8941 3eca fdbb        E..........A>...
0x0010   d462 2894 0d25 0019 2513 eec4 f7b1 e6c9        .b(..%..%.......
0x0020   5018 2000 b206 0000 5253 4554 0d0a             P.......RSET..
19:25:52.349231 212.98.40.148.25 > 62.202.253.187.3365: P 281:295(14) ack 74 win 5800 (DF)
0x0000   4500 0036 608f 4000 4006 a0b6 d462 2894        E..6`.@.@....b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e6c9 2513 eeca        >......%....%...
0x0020   5018 16a8 676c 0000 3235 3020 5265 7365        P...gl..250.Rese
0x0030   7420 4f4b 0d0a                                 t.OK..
19:25:53.039131 62.202.253.187.3365 > 212.98.40.148.25: P 74:98(24) ack 295 win 8192
0x0000   4500 0040 000d 0000 f806 892e 3eca fdbb        E..@........>...
0x0010   d462 2894 0d25 0019 2513 eeca f7b1 e6d7        .b(..%..%.......
0x0020   5018 2000 ec0a 0000 4d41 494c 2046 524f        P.......MAIL.FRO
0x0030   4d3a 3c66 6240 6c74 6563 2e63 683e 0d0a        M:<fb@???>..
19:25:53.040096 212.98.40.148.25 > 62.202.253.187.3365: P 295:303(8) ack 98 win 5800 (DF)
0x0000   4500 0030 6090 4000 4006 a0bb d462 2894        E..0`.@.@....b(.
0x0010   3eca fdbb 0019 0d25 f7b1 e6d7 2513 eee2        >......%....%...
0x0020   5018 16a8 a137 0000 3235 3020 4f4b 0d0a        P....7..250.OK..
19:25:53.693803 62.202.253.187.3365 > 212.98.40.148.25: P 98:125(27) ack 303 win 8192
0x0000   4500 0043 000e 0000 f806 892a 3eca fdbb        E..C.......*>...
0x0010   d462 2894 0d25 0019 2513 eee2 f7b1 e6df        .b(..%..%.......
0x0020   5018 2000 c757 0000 5243 5054 2054 4f3a        P....W..RCPT.TO:
0x0030   3c6c 7465 6340 626c 7565 7769 6e2e 6368        <ltec@???
0x0040   3e0d 0a                                        >..
------------------ tcpdump log ends here ------------------------


Just for completeness, here is the authenticator that was in
question:

lookup_login:
driver = plaintext
public_name = LOGIN
server_prompts = "Username:: : Password::"
server_condition = ${lookup{$1}lsearch{/usr/local/exim/auth.passwd}{${if eq{$value}{$2}{yes}{no}}}{no}}
server_set_id = $1

Perhaps the answer to my question is: "There is no option that makes exim
log usernames or passwords due to security reasons"?

-------------------------

Felix

Philip Hazel wrote:

PH> On Thu, 2 Mar 2006, Felix Brack wrote:


>> Many thanks for your response. I often use tcpdump or ethereal to
>> debug communication but if the program in question has it's own
>> debugging features, I normally preferre these. Just for clarity: there
>> is no debug option in exim that would enable showing things like
>> username and password entered on the remote client during the SMTP
>> session?


PH> That debug looks odd. It should show the entire SMTP dialogue, unless
PH> I'm going mad (which is always possible). Some definitive info from
PH> tcpdump should help settle this. You could also show us the
PH> configuration of your LOGIN authenticator.


PH> -- 
PH> Philip Hazel            University of Cambridge Computing Service
PH> Get the Exim 4 book:    http://www.uit.co.uk/exim-book