Printing Slowness

Have you come across complaints from business users that the outputs take a long time for printing?

We had this issue of printing slowness.

Issue

When a customer came into the shop, bought some product, and made the payment, the employee would run our custom transaction which would trigger a smartform and a Payment receipt would be generated.

There were many such shops. Some of the shops reported that there were times when the customer had to wait for about 1-2 minutes before the receipt was printed. There were times when the receipt was generated within 10-15 seconds.

This is how the business described the issue to our development team. We did not have much info other than the custom transaction.

On further probing, it was revealed that they were issuing a print in Black & White.

Trying to find the cause

With this limited information, we initially thought that it was some issue related to Basis which somehow caused a slowness.

Also, being ready with trace in the Production system waiting for the shop-employee to run the custom transaction and analyzing the issue did not seem plausible.

We tried setting trace in Quality system, but all seemed good from ABAP side.

Urgency from Business

The business wanted to get this resolved on high priority.

The issue was known but the cause was not known and so there was no replication of issue possible.

So, we set out on a journey (which in hindsight, seems a long route :P) to find the issue first and then hopefully resolve it quickly. We started to gather all the data and analyze the data to find the issue.

For people who are interested in the journey, I request you to stick around.

The Cause

The cause of the issue was a marketing image on the bill. The image (which was uploaded as a color image in transaction SE78) was regarding a new app the company had created for online orders that took up almost 30 % of the page.

The image was printed based on some condition. When we had the image on the printout, the printout came out slow. When there was no image in the printout, the print came fast. (The development team was not aware of this when the issue came to us)

I did some reading later and found that every time a smartform is printed the graphic gets loaded in table TST03 and the table gets large and this slows down the printing. In our case, the image was non-compressed and quite large. This image was 18cm x 6cm non-compressed color image.

The journey – Data Gathering and Analysis

We decided to gather details like the Bill Number, Spool number the detailed times of the printouts and stored them in a custom table and created a report that would update this table. The report ran as a background job every 30 minutes in the system.

We created the custom table as shown below:

Custom table for Spool details

We added a few lines of code after calling the smartform.

DATA: lt_spool TYPE TABLE OF zspool.

CALL FUNCTION g_fmname

  EXPORTING

    control_parameters = g_control_parameters

    output_options     = g_output_options

          .                  .

          .                  .

          .                  .

  IMPORTING

    job_output_info    = g_output_data

  EXCEPTIONS

    formatting_error   = 1

    internal_error     = 2

    send_error         = 3

    user_canceled      = 4

    OTHERS             = 5.

IF sy-subrc = 0.

  READ TABLE g_output_data-spoolids INDEX 1 INTO lv_spool.

  IF sy-subrc EQ 0.

    APPEND INITIAL LINE TO lt_spool ASSIGNING <ls_spool>.

    <ls_spool>-document_num = g_bill_number.

    <ls_spool>-spool = lv_spool.

  ENDIF.

  MODIFY zspool FROM TABLE lt_spool.

  IF sy-subrc EQ 0.

    COMMIT WORK.

  ENDIF.

ENDIF.

Some excerpts from the custom report

* The report ran every 30 minutes

CALL FUNCTION 'START_TIME_DETERMINE'

  EXPORTING

    duration                   = 30

    unit                       = 'MIN'

  IMPORTING

    start_date                 = lv_date

    start_time                 = lv_time

  CHANGING

    end_date                   = sy-datum

    end_time                   = sy-uzeit

  EXCEPTIONS

    factory_calendar_not_found = 1

    date_out_of_calendar_range = 2

    date_not_valid             = 3

    unit_conversion_error      = 4

    si_unit_missing            = 5

    parameters_not_valid       = 6

    OTHERS                     = 7.

* Getting the bill numbers

SELECT belnr

  FROM bkpf

  INTO TABLE lt_bkpf

  WHERE cpudt GE lv_date

  AND   cputm GE lv_time.

IF sy-subrc EQ 0.

* Selecting the relevant documents

  SELECT * FROM zspool

  INTO TABLE gt_spool

  FOR ALL ENTRIES IN lt_bkpf

  WHERE document_num = lt_bkpf-belnr

  AND   status NE ‘9’. “Status 9 implies process completed

ENDIF.

* Fetch the spool requests data

IF gt_spool IS NOT INITIAL.

  SELECT rqident

         rqcretime

  FROM tsp01

  INTO TABLE gt_tsp01

  FOR ALL ENTRIES IN gt_spool

  WHERE rqident = gt_spool-spool.

  SELECT pjident

         pjnummer

         pjstatus

         pjstrttime

         pjaendtime

         pjhendtime

  FROM tsp02

  INTO TABLE gt_tsp02

  FOR ALL ENTRIES IN gt_spool

  WHERE pjident = gt_spool-spool.

ENDIF.

LOOP AT gt_spool ASSIGNING <ls_spool>.

* Making the time stamps more readable to the eye

* for storing in the custom table

  READ TABLE gt_tsp01 ASSIGNING <ls_tsp01>

    WITH KEY rqident = <ls_spool>-spool

    BINARY SEARCH.

  IF sy-subrc EQ 0.

    <ls_spool>-rqcret_date = <ls_tsp01>-rqcretime+0(8).

    <ls_spool>-rqcret_time = <ls_tsp01>-rqcretime+8(6).

  ENDIF.

  READ TABLE gt_tsp02 ASSIGNING <ls_tsp02>

    WITH KEY pjident = <ls_spool>-spool

    BINARY SEARCH.

  IF sy-subrc EQ 0.

    <ls_spool>-pjstatus    = <ls_tsp02>-pjstatus.

    <ls_spool>-pjstrt_date = <ls_tsp02>-pjstrttime+0(8).

    <ls_spool>-pjstrt_time = <ls_tsp02>-pjstrttime+8(6).

    <ls_spool>-pjaend_date = <ls_tsp02>-pjaendtime+0(8).

    <ls_spool>-pjaend_time = <ls_tsp02>-pjaendtime+8(6).

    <ls_spool>-pjhend_date = <ls_tsp02>-pjhendtime+0(8).

    <ls_spool>-pjhend_time = <ls_tsp02>-pjhendtime+8(6).

  ENDIF.

ENDLOOP.

MODIFY zspool FROM TABLE gt_spool.

And just like that, the report was ready. We transported the report to Production and let the batch job run for a week. At the end of the week, we had gathered enough data.

Observations:

◉ There was not much time gap between time at which spool was created and time of output request creation suggesting that there was not much wrong at the ABAP side after the smartform was called and spool generated.

◉ Next, there were records where there was a considerable time gap between Output request creation and Output request transferred to Print server.

◉ We checked the spools of a bunch of these records and they had the Marketing Color Image.

◉ We checked the spools of those records where there wasn’t as considerable a time gap and they had NO Marketing Image.

SO THAT WAS IT…

We knew the issue now and quickly replicated this in Development system. We ran our report and the data in the table looked like this.

The top 2 entries were spools with the Marketing Image (a time gap of almost 40 seconds)

The next 2 entries were without the Image (time gap of just about 7 seconds)

Solution

Clearly it was the large image that was causing the issue. But since we knew that the final receipts issued to the customer were in Black & White, we uploaded the marketing image as a Black & White compressed image in SE78 again.

We adjusted the smartform to print Black & White Image. We tested this in Development system. We ran the report and looked at the numbers. The the time gap was just under 15 seconds (a considerable improvement).