accessing certain fields by tag number duplicates subsequent log messages

[GoogleCodeExporter]

What steps will reproduce the problem?

run this code:

import dicom, logging
mylogger = logging.getLogger('mylogger')
mylogger.addHandler(logging.StreamHandler())

dcm = dicom.read_file('1.dcm')
mylogger.error('once')

dcm.PatientsName
dcm[0x0010, 0x0010]
mylogger.error('once again')

dcm[0x0019, 0x10e0]
mylogger.error('twice')

What is the expected output? What do you see instead?

once
once again
twice
ERROR:mylogger:twice

All log messages should appear exactly once, but after accessing a certain 
field by tag number, subsequent log messages appear twice. Note the different 
formatting of the last log message. It seems as if a second handler has gotten 
attached to "mylogger".

What version of the product are you using?

0.9.5 on Ubuntu 11.04 (GNU/Linux 2.6.38-11-generic x86_64)

Please provide any additional information below.

Here is a trace:

>>> import dicom, logging
>>> mylogger = logging.getLogger('mylogger')
>>> mylogger.addHandler(logging.StreamHandler())
>>> 
>>> dcm = dicom.read_file('1.dcm')
>>> mylogger.error('once')
once
>>> 
>>> dcm.PatientsName
'phantom^mister'
>>> dcm[0x0010, 0x0010]
(0010, 0010) Patient's Name                      PN: 'phantom^mister'
>>> mylogger.error('once again')
once again
>>> 
>>> dcm[0x0019, 0x10e0]
(0019, 10e0) [User data 24 {# DTI Diffusion Dir. DS: '0.000000'
>>> mylogger.error('twice')
twice
ERROR:mylogger:twice

Original issue reported on code.google.com by gunnar.s...@gmail.com on 28 Oct 2011 at 9:58

Attachments:

• 1.dcm

[GoogleCodeExporter]

I was able to reproduce the same sequence using your code. No idea how that 
could happen, and as you noted it is particular to accessing a certain tag 
number (or any private tag?). Will have to try to trace through the code and 
see what might be happening.

Original comment by darcymason@gmail.com on 4 Nov 2011 at 1:20

• Changed state: Accepted

[GoogleCodeExporter]

Patch attached. Use of logging.debug() instead of logger.debug() in 
dicom/dataset.py:525 implicitly adds a handler to the root logger.

Original comment by gunnar.s...@gmail.com on 28 Apr 2012 at 12:07

Attachments:

• dataset.py.patch

[GoogleCodeExporter]

Nice find. Will apply to 09x series clone and to main branch heading for 
pydicom 1.0.

Original comment by darcymason@gmail.com on 28 Apr 2012 at 10:17

[GoogleCodeExporter]

This issue was closed by revision 774b7a55db33.

Original comment by darcymason@gmail.com on 28 Apr 2012 at 10:28

• Changed state: Fixed