[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF begin '4' received on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF begin ignored '4' on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end '4' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end passthrough '4' on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end '4' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end passthrough '4' on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end '4' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF end passthrough '4' on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF begin '3' received on SIP/462-00000000
[2012-09-14 11:50:05] DTMF[32019] channel.c: DTMF begin ignored '3' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '3' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '3' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '3' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '3' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '3' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '3' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF begin '0' received on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF begin ignored '0' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '0' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '0' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '0' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '0' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '0' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '0' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF begin '#' received on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF begin ignored '#' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '#' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end passthrough '#' on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '#' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '#' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF begin emulation of '#' with duration 300 queued on SIP/462-00000000
[2012-09-14 11:50:06] DTMF[32019] channel.c: DTMF end '#' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:07] DTMF[32019] channel.c: DTMF end emulation of '#' queued on SIP/462-00000000
[2012-09-14 11:50:07] DTMF[32019] channel.c: DTMF end '#' received on SIP/462-00000000, duration 300 ms
[2012-09-14 11:50:07] DTMF[32019] channel.c: DTMF begin emulation of '#' with duration 300 queued on SIP/462-00000000

As a comparison here is an excerpt from the DTMF log of a similar call from the same extension before the upgrade (Asterisk 1.8.15.1):

[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin '4' received on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin ignored '4' on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF end '4' received on SIP/462-0000007b, duration 300 ms
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF end passthrough '4' on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin '3' received on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin ignored '3' on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF end '3' received on SIP/462-0000007b, duration 300 ms
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF end passthrough '3' on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin '0' received on SIP/462-0000007b
[2012-09-13 14:41:25] DTMF[7934] channel.c: DTMF begin ignored '0' on SIP/462-0000007b
[2012-09-13 14:41:26] DTMF[7934] channel.c: DTMF end '0' received on SIP/462-0000007b, duration 300 ms
[2012-09-13 14:41:26] DTMF[7934] channel.c: DTMF end passthrough '0' on SIP/462-0000007b
[2012-09-13 14:41:27] DTMF[7934] channel.c: DTMF begin '#' received on SIP/462-0000007b
[2012-09-13 14:41:27] DTMF[7934] channel.c: DTMF begin ignored '#' on SIP/462-0000007b
[2012-09-13 14:41:27] DTMF[7934] channel.c: DTMF end '#' received on SIP/462-0000007b, duration 300 ms

No changes in the environment, no changes to the Soft Phone settings

I did resolve the issue by switching Soft Phones, and the difference is in DTMF duration as I can see.

[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin '4' received on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin ignored '4' on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end '4' received on SIP/462-0000000e, duration 120 ms
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end passthrough '4' on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin '3' received on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin ignored '3' on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end '3' received on SIP/462-0000000e, duration 100 ms
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end passthrough '3' on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin '0' received on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF begin ignored '0' on SIP/462-0000000e
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end '0' received on SIP/462-0000000e, duration 160 ms
[2012-09-14 13:43:02] DTMF[32606] channel.c: DTMF end passthrough '0' on SIP/462-0000000e
[2012-09-14 13:43:03] DTMF[32606] channel.c: DTMF begin '#' received on SIP/462-0000000e
[2012-09-14 13:43:03] DTMF[32606] channel.c: DTMF begin ignored '#' on SIP/462-0000000e
[2012-09-14 13:43:03] DTMF[32606] channel.c: DTMF end '#' received on SIP/462-0000000e, duration 80 ms