• Topic ID: id_11038941
  • Version: 3.0
  • Date: Apr 22, 2019 12:56:06 AM

Troubleshooting DICOM Print Camera Problems

LOG OF ERROR AND FILMING STATUS

During DICOM Print filming, the system writes to two camera logfiles, dcplog and prslog. When a print job starts, the dicom information is logged to ~ctuser/logfiles/dcplog. The print job information is logged to ~ctuser/logfiles/prslog. The called AE title/host/IP/port number is taken from ~ctuser/Prefs/SdCPHosts file.

1 dcplog

This logfile contains dicom print filming sequence and Printer status information for the most recent print session job. Each time a new print job is performed, the status information for that latest job will overwrite the previous one.

1.1 Printer Status Area in the dcplog report

The Printer Status area in the log report will either be NORMAL, WARNING, or FAILURE. In the event of a WARNING or FAILURE, the Status Info field attempted to identify the root cause.

NORMAL - print job was successful, no problems.

WARNING - one of three conditions can happen:

  1. The job aborts and the status info field indicates SUPPLY FULL, RECEIVER FULL, or FILM JAM. (See part 3 below for FILM JAM example.)

  2. The job continues and Warning is posted to the operator if Status Info field reports SUPPLY LOW.

  3. The job continues and a Warning is not posted to the operator, but the message is put in dcplog file.

    note:

    What gets reported is dependent upon the camera type and the camera server’s ability to report it.

    FAILURE - the print job has aborted; see Status Info field for more information.

1.2 Dcplog example of a print job leading up to a Film Jam


{ctuser@engbayXX}[17] cd /usr/g/ctusr/logfiles
{ctuser@engbayXX}[18] more dcplog
_[40;1H_[K# DICOM print_scu pid: 5463
print_scu -aIMN -hcamera -c1 -f1x1_fid -p/usr/g/ctuser/film/img21a0017f -d/usr/g/ctuser/app-defaults/devices/camera.dev
dcm_bind: AETitle = engbay26_DCP
map_app_title: title IMN host camera ip-addr 3.7.52.164 port 2104
EstablishAssoc: DCM_OPEN_REQ Action success
EstablishAssoc: OPEN_CONF received
Starting the print session
NgetService: Event Received : DCM_NGET_END
NgetService: Event Received : DCM_DATA
          

1.3 Known error reported from Nget with Imation Cameras that should not be troubleshot:

The prslog reports:


MESSAGE from Process 2059 >> Wed Aug 19 10:03:48 1998  [PRSserver]> Print job started
Message from Process 2060 >> NgetService: N-GET response received with failure/warning Status
Message from Process 2060 >> AETitle: IMN_PrintServer
Message from Process 2060 >> Print Session successfully completed
          

The dcplog reports:


NgetService: N-GET response received with failure/warning Status  ¨the known error.
          

What Imation supports:

Imation supports the following six elements/attributes:


> (0x21100010, CS, ”NORMAL”)  # Printer Status OK
> (0x21100020, CS, ””)  # Printer Status Info OK
> (0x21100030, LO, ”IMN_LaserImager”)  # Printer Name OK
> (0x00080070, LO, ”Imation”)  # Manufacturer OK
> (0x00081090, LO, ”M8700”)  # Manufacturer’s Model Name OK
> (0x00181020, LO, ”1.5b4”)  # Software Versions OK
          

The Bug:

Nget is requesting status from these three additional elements that are not supported:


>  (0x00181000, LO, ””)  # Device Serial Number
>  (0x00181200, DA, ””)  # Date of Last Calibration
>  (0x00181201, TM, ””)  # Time of Last Calibration
          

The Fix:

Instruct Camera FE to disable the above three elements that are not supported.

1.4 Communication and Network Error Troubleshooting

The most common types of network errors that can occur with DICOM Print are a:

  • DCM Network error and

  • DCM Protocol error.

1.4.1 DCM Network Errors

Successful network communications to the camera are dependent on a correctly configured IP Address and Port Number. Any errors associated with the network log as a “DCM Network Error” in the “type” field in the dcplog report, as shown in the example below. Use ping and snoop to discover the root cause, covered in the troubleshooting steps below.

Example of dcplog with a DCM Network Error:

{ctuser@engbayXX}[3] cd /usr/g/ctusr/logfiles

{ctuser@engbayXX}[4] more dcplog


_[40;1H_[K# DICOM print_scu pid: 5498
print_scu -aIMN -hcamera -c1 -f1x1_fid -p/usr/g/ctuser/film/img22a0017f -d/usr/g/ctuser/app-defaults/devices/camera.dev
dcm_bind: AETitle = engbay26_DCP
map_app_title: title IMN host camera ip-addr 3.7.52.164 port 2104
EstablishAssoc: DCM_OPEN_REQ Action success
            

Errors logged beyond this point of failure may be a result of this Error:

DCM kernel lower level error:


type = 508 -- DCM network error    ¨ ERROR
code = 114 -- lost transport connection
ul_code = 52, reason = 0, source = 0, reject = 0
filename = kernel/D_assoc.c  line = 3051
Failed to contact printer, status 114
            

Steps for troubleshooting a DCM Network Error:

  1. Verify correct IP Address and Port Number are correct in the Install Camera GUI.

    note:

    If the IP Address and Port Number are correct, the remote application (camera server) may not be running.

  2. Verify Applications restarted after running Install Camera from Service Desktop Utilities.

  3. Verify on the OC in /usr/g/ctuser/SdCPHosts the IP Address and Port Number are correct.

    Enter the following:

    ctuser@bayXX}[2] cd /usr/g/ctuser/Prefs

    ctuser@bayXX}[3] cat SdCPHosts

    3.7.52.164 camera IMN 2106 ctn display

  4. Ping to the camera’s IP address, and check for packet loss. A successful ping indicates a good physical connection and IP Address. Port number can still be bad; proceed to next step.

    Example of successful ping:

    {ctuser@engbayXX}[5] ping 3.7.52.164

    PING 3.7.52.164 (3.7.52.164): 56 data bytes

    64 bytes from 3.7.52.164: icmp_seq=0 ttl=255 time=0.927 ms

    64 bytes from 3.7.52.164: icmp_seq=1 ttl=255 time=1.079 ms

    64 bytes from 3.7.52.164: icmp_seq=2 ttl=255 time=1.090 ms

    64 bytes from 3.7.52.164: icmp_seq=3 ttl=255 time=1.070 ms

    64 bytes from 3.7.52.164: icmp_seq=4 ttl=255 time=1.048 ms

    64 bytes from 3.7.52.164: icmp_seq=5 ttl=255 time=1.073 ms

    64 bytes from 3.7.52.164: icmp_seq=6 ttl=255 time=1.199 ms

    ----3.7.52.164 PING Statistics----

    7 packets transmitted, 7 packets received, 0% packet loss

    round-trip min/avg/max = 0.927/1.069/1.199 ms

  5. If you are unable to successfully ping the camera, use the snoop tool to monitor what is going on with communication packets during a print job. Snoop will read the number of responses from the server while attempting to do a print job. In Example A below, there is only one summary line being reported, (one outbound), and NO inbound response indicating the remote camera host (engctnl) cannot be reached. Refer to Snoop for snoop and its usage.

    Example: Example A:

    snoop -SVta 3.7.52.164 ←where 3.7.52.164 in this case is the camera <IP address>

    Using device ef0 (promiscuous mode)

    14:46:19.250400 engbay26 -> engctn1 length: 58 ETHER Type=0800 (IP), size = 58 bytes

    14:46:19.250400 engbay26 -> engctn1 length: 58 IP D=3.7.52.164 S=3.7.52.151 LEN=44, ID=57050

    14:46:19.250400 engbay26 -> engctn1 length: 58 TCP D=2106 S=1192 Syn Seq=1001039841 Len=0 Win=16384

  6. If there are only two summary lines, (Example B below) one outbound and one inbound, this indicates that we can successfully ping the remote camera host, (IP Address is good) but the remote application is either not running (i.e. the machine is up, the application that acts as the print server is not running), or the wrong port number is being used. Refer to Snoop for snoop and its usage.

    Example B:

    snoop -SVta 3.7.52.164 ← where 3.7.52.164 in this case is the camera <IP address>

    Using device ef0 (promiscuous mode)

    14:46:19.250400 engbay26 -> engctn1 length: 58 ETHER Type=0800 (IP), size = 58 bytes

    14:46:19.250400 engbay26 -> engctn1 length: 58 IP D=3.7.52.164 S=3.7.52.151 LEN=44, ID=57050

    14:46:19.250400 engbay26 -> engctn1 length: 58 TCP D=2106 S=1192 Syn Seq=1001039841 Len=0 Win=16384

    ________________________________

    14:46:19.251971 engctn1 -> engbay26 length: 60 ETHER Type=0800 (IP), size = 60 bytes

    14:46:19.251971 engctn1 -> engbay26 length: 60 IP D=3.7.52.151 S=3.7.52.164 LEN=40, ID=10027

    14:46:19.251971 engctn1 -> engbay26 length: 60 TCP D=1192 S=2106 Rst Ack=1001039842 Win=0

    Example C below shows what would be logged in the dcplog with incorrect port number problem. This is really a tcp initialization error, attempting to open an association, the remote host is up and running but the port number is wrong. Note: this same error can also be caused by the remote application (camera server) not running.

    Example C:

    {ctuser@engbayXX}[17] cd /usr/g/ctusr/logfiles

    {ctuser@engbayXX}[18] more dcplog

    # DICOM print_scu pid: 2523

    print_scu -aIMN -hengctn1 -c1 -f1x1_fid -p./1on1 -d./camera.dev

    dcm_bind: AETitle = engbay26_DCP

    map_app_title: title IMN host engctn1 ip-addr 3.7.52.164 port 2106

    EstablishAssoc: DCM_OPEN_REQ Action success

    Errors logged beyond this point of failure may be a result of this Error:

    DCM kernel lower level error:

    type = 508 -- DCM network error " ERROR

    code = 114 -- lost transport connection

    ul_code = 52, reason = 0, source = 0, reject = 0

    filename = kernel/D_assoc.c line = 3051

    Failed to contact printer, status 114

1.4.2 DCM Protocol Error

A DCM Protocol Error indicates a problem with calling parameters when trying to open an association. They can be caused by having an incorrect AE Title configuration. The errors reported by a print server are only as good as the dicom implementation of that server. The Imation server will accept any called AE title. The Kodak mlp190 accepts any called AE title. The AGFA however, requires the AE to match. The following examples display what is reported in the dcplog, with an incorrect AE Title on an AGFA system (Example D), and what snoop reports (Example E).

Example D:


cd /usr/g/ctuser/logfiles
more dcplog
print_scu -aIMN1 -hengctn1 -c1 -f1x1_fid -p./1on1 -d./camera.dev
# DICOM print_scu pid: 2492
print_scu -aIMN1 -hengctn1 -c1 -f1x1_fid -p./1on1 -d./camera.dev
dcm_bind: AETitle = engbay26_DCP
map_app_title: title IMN1 host engctn1 ip-addr 3.7.52.164 port 2106
EstablishAssoc: DCM_OPEN_REQ Action success
Errors logged beyond this point of failure may be a result of this Error:
DCM kernel lower level error:
type = 507 -- DCM Protocol error  ERROR
code = 166 -- invalid PDU parameter value
ul_code = 37, reason = 0, source = 0, reject = 0
filename = kernel/D_assoc.c  line = 3051
DCM kernel lower level error:
type = 503 -- DCM Kernel integrity errors
code = 136 -- error with the dicom upper layer
ul_code = 22, reason = 0, source = 0, reject = 0
filename = kernel/D_assoc.c  line = 500
Fatal DCM error: 136
dcm_deinit: Kernel Deinit Failed
Failed to contact printer, status 166
            

Example E:

The number of packets, outbound and inbound with length of ~60 and ~500 indicates that the remote application is running, but it is not allowing the SCU (Service Class User, i.e. the OC) to open an association. This also indicates the IP Address and Port Number is correct.

engbay26 2# snoop -SVta <camera IP address>

Using device ef0 (promiscuous mode)


15:10:36.357083     engbay26 -> engctn1      length:   58  ETHER Type=0800 (IP), size = 58 bytes
15:10:36.357083     engbay26 -> engctn1      length:   58  IP  D=3.7.52.164 S=3.7.52.151 LEN=44, ID=59135
15:10:36.357083     engbay26 -> engctn1      length:   58  TCP D=2106 S=1209 Syn Seq=1188358241 Len=0 Win=16384
________________________________
15:10:36.358280      engctn1 -> engbay26     length:   60  ETHER Type=0800 (IP), size = 60 bytes
15:10:36.358280      engctn1 -> engbay26     length:   60  IP  D=3.7.52.151 S=3.7.52.164 LEN=44, ID=37125
15:10:36.358280      engctn1 -> engbay26     length:   60  TCP D=1209 S=2106 Syn Ack=1188358242 Seq=1847802416 Len=0 Win=8760
________________________________
15:10:36.358390     engbay26 -> engctn1      length:   54  ETHER Type=0800 (IP), size = 54 bytes
15:10:36.358390     engbay26 -> engctn1      length:   54  IP  D=3.7.52.164 S=3.7.52.151 LEN=40, ID=59137
15:10:36.358390     engbay26 -> engctn1      length:   54  TCP D=2106 S=1209     Ack=1847802417 Seq=1188358242 Len=0 Win=16060
________________________________
15:10:36.361533     engbay26 -> engctn1      length:  456  ETHER Type=0800 (IP), size = 456 bytes
15:10:36.361533     engbay26 -> engctn1      length:  456  IP  D=3.7.52.164 S=3.7.52.151 LEN=442, ID=59138
15:10:36.361533     engbay26 -> engctn1      length:  456  TCP D=2106 S=1209     Ack=1847802417 Seq=1188358242 Len=402 Win=16060
________________________________
15:10:36.412509      engctn1 -> engbay26     length:   60  ETHER Type=0800 (IP), size = 60 bytes
15:10:36.412509      engctn1 -> engbay26     length:   60  IP  D=3.7.52.151 S=3.7.52.164 LEN=40, ID=37126
15:10:36.412509      engctn1 -> engbay26     length:   60  TCP D=1209 S=2106     Ack=1188358644 Seq=1847802417 Len=0 Win=8760
________________________________
15:10:36.424127      engctn1 -> engbay26     length:   64  ETHER Type=0800 (IP), size = 64 bytes
15:10:36.424127      engctn1 -> engbay26     length:   64  IP  D=3.7.52.151 S=3.7.52.164 LEN=50, ID=37127
15:10:36.424127      engctn1 -> engbay26     length:   64  TCP D=1209 S=2106     Ack=1188358644 Seq=1847802417 Len=10 Win=8760
________________________________
15:10:36.424376     engbay26 -> engctn1      length:   64  ETHER Type=0800 (IP), size = 64 bytes
15:10:36.424376     engbay26 -> engctn1      length:   64  IP  D=3.7.52.164 S=3.7.52.151 LEN=50, ID=59141
15:10:36.424376     engbay26 -> engctn1      length:   64  TCP D=2106 S=1209     Ack=1847802427 Seq=1188358644 Len=10 Win=16060
________________________________
15:10:36.428902      engctn1 -> engbay26     length:   60  ETHER Type=0800 (IP), size = 60 bytes
15:10:36.428902      engctn1 -> engbay26     length:   60  IP  D=3.7.52.151 S=3.7.52.164 LEN=40, ID=37128
15:10:36.428902      engctn1 -> engbay26     length:   60  TCP D=1209 S=2106 Fin Ack=1188358654 Seq=1847802427 Len=0 Win=8760
________________________________
15:10:36.428975     engbay26 -> engctn1      length:   54  ETHER Type=0800 (IP), size = 54 bytes
15:10:36.428975     engbay26 -> engctn1      length:   54  IP  D=3.7.52.164 S=3.7.52.151 LEN=40, ID=59143
15:10:36.428975     engbay26 -> engctn1      length:   54  TCP D=2106 S=1209     Ack=1847802428 Seq=1188358654 Len=0 Win=16060
________________________________
            

note:

If the AE title is correct, the server may have a security feature that requires that the local host be registered on the remote host.

Image Packet Transfer, Output From snoop

This is an excerpt from a snoop output representing actual image packets, (length ~1514), being transferred to the camera:


________________________________
12:19:58.436211     engbay26 -> engctn1      length: 1514  ETHER Type=0800 (IP), size = 1514 bytes
12:19:58.436211     engbay26 -> engctn1      length: 1514  IP  D=3.7.52.164 S=3.7.52.151 LEN=1500, ID=38793
12:19:58.436211     engbay26 -> engctn1      length: 1514  TCP D=2106 S=1511     Ack=3095191028 Seq=1815234494 Len=1460 Win=16060
________________________________
12:19:58.436256     engbay26 -> engctn1      length: 1514  ETHER Type=0800 (IP), size = 1514 bytes
12:19:58.436256     engbay26 -> engctn1      length: 1514  IP  D=3.7.52.164 S=3.7.52.151 LEN=1500, ID=38794
12:19:58.436256     engbay26 -> engctn1      length: 1514  TCP D=2106 S=1511     Ack=3095191028 Seq=1815235954 Len=1460 Win=1606
            

2 Snoop

Snoop (snoop) is the troubleshooting tool that monitors all the communication and image packets inbound and outbound to the camera during a print job (depending on switch settings). The packet size length is important in understanding what is being transferred. A length size of < 500 indicates requests and responses between the scanner and the print server. These are from the NGET (printer status), and NCREATE (film session and film box). A series of packet lengths of about 1500 indicates an image transfer in progress. This applies to both dicom print and dicom send.

The following examples show common uses of snoop. See Number 3, below, for a description of snoop usage and switch descriptions. Typical use examples:

  1. How to display outgoing and in-going packets:

    {ctuser@bayXX}[3] su -

    password

    bayxx 1# snoop -SVta <camera ip address>

    Using device ef0 (promiscuous mode)

    15:00:18.606959 engbay26 -> engctn1 length: 58 ETHER Type=0800 (IP), size = 58 bytes

    15:00:18.606959 engbay26 -> engctn1 length: 58 IP D=3.7.52.164 S=3.7.52.151 LEN=44, ID=59593

    15:00:18.606959 engbay26 -> engctn1 length: 58 TCP D=2104 S=3565 Syn Seq=1295817451 Len=0 Win=16384

    15:00:18.608481 engctn1 -> engbay26 length: 60 ETHER Type=0800 (IP), size = 60 bytes

    15:00:18.608481 engctn1 -> engbay26 length: 60 IP D=3.7.52.151 S=3.7.52.164 LEN=40, ID=33153

    15:00:18.608481 engctn1 -> engbay26 length: 60 TCP D=3565 S=2104 Rst Ack=1295817452 Win=0

  2. How to display incoming packets only:

    {ctuser@bayXX}[3] su -

    password

    bayxx 1# snoop -SPVta <camera ip address>

    Using device ef0 (promiscuous mode)

    14:58:54.506391 engctn1 -> engbay26 length: 60 ETHER Type=0800 (IP), size = 60 bytes

    14:58:54.506391 engctn1 -> engbay26 length: 60 IP D=3.7.52.151 S=3.7.52.164 LEN=40, ID=14589

    14:58:54.506391 engctn1 -> engbay26 length: 60 TCP D=3563 S=2104 Rst Ack=1285065404 Win=0

  3. Usage for snoop:

    [ -a ] # Listen to packets on audio

    [ -d device ] # settable to le?, ie?, bf?, tr?

    [ -s snaplen ] # Truncate packets

    [ -c count ] # Quit after count packets

    [ -P ] # Turn OFF promiscuous mode

    [ -D ] # Report dropped packets

    [ -S ] # Report packet size

    [ -i file ] # Read previously captured packets

    [ -o file ] # Capture packets in file

    [ -n file ] # Load addr-to-name table from file

    [ -N ] # Create addr-to-name table

    [ -t r|a|d ] # Time: Relative, Absolute or Delta

    [ -v ] # Verbose packet display

    [ -V ] # Show all summary lines

    [ -p first[,last] ] # Select packet(s) to display

    [ -x offset[,length] ] # Hex dump from offset for length

    [ -C ] # Print packet filter code

    For additional information, refer to the manual page for snoop. To do so, open a Unix shell, and enter the following:

    su -

    password

    man snoop