disp+work die automatically

[former_member211576]

Hi experts,

   I found 2 of 19 disp+work processes die automatically. I cut a few error messages below but I am not sure if this is the source of the problem. I upload a full log in the attachment. Please help.

---

Mon Sep 22 08:19:17 2014

DpHdlDeadWp: W28 (pid=4464) terminated automatically

Mon Sep 22 08:28:22 2014

*** ERROR => DpRqCheck: T103 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  103   wp_ca_blk   3       wp_id 28

-IN-- action    SEND_TO_WP        uid  24012   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 56725

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

Mon Sep 22 08:58:59 2014

***LOG Q0I=> NiIRead: P=10.17.31.131:52865; L=10.243.23.105:3232: recv (10054: WSAECONNRESET: Connection reset by peer) [nixxi.cpp 5082]

*** ERROR => NiIRead: SiRecv failed for hdl 258/sock 1656

    (SI_ECONN_BROKEN/10054; I4; ST; P=10.17.31.131:52865; L=10.243.23.105:3232) [nixxi.cpp    5082]

DpRTmPrepareReq: network error of client T81, NiBufReceive (-6: NIECONN_BROKEN), dp_tm_status=3

DpRTmPrepareReq: client address of T81 is 10.17.31.131(10.17.31.131)

***LOG Q04=> DpRTmPrep, NiBufReceive (24283A1120001 81 CQ-SAP01A ) [dpxxdisp.c   12455]

RM-T81, U24283, 218     A1120001, CQ-SAP01A, 08:55:22, M2, W20, ZP9N, 4/2

Mon Sep 22 09:06:52 2014

SoftCancel request for T71 U24272 M0 received from REMOTE_TERMINAL

Mon Sep 22 09:07:18 2014

DpHdlDeadWp: W2 (pid=6248) terminated automatically

Mon Sep 22 09:43:56 2014

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   5       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46131

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   3       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46132

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   6       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46133

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   7       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46134

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   10      wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46135

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   9       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46136

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   0       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46137

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   11      wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46138

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   12      wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46139

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   13      wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46140

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   16      wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46141

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

*** ERROR => DpRqCheck: T61 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  61    wp_ca_blk   8       wp_id 20

-IN-- action    SEND_TO_WP        uid  24896   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 46142

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

Mon Sep 22 10:17:41 2014

DpCheckTerminals: gui_auto_logout time exceeded for T92 but M0 still active - logout delayed

Mon Sep 22 10:18:10 2014

***LOG Q0I=> NiIRead: P=172.20.166.147:61268; L=10.243.23.105:3232: recv (10054: WSAECONNRESET: Connection reset by peer) [nixxi.cpp 5082]

*** ERROR => NiIRead: SiRecv failed for hdl 524/sock 1824

    (SI_ECONN_BROKEN/10054; I4; ST; P=172.20.166.147:61268; L=10.243.23.105:3232) [nixxi.cpp    5082]

DpRTmPrepareReq: network error of client T92, NiBufReceive (-6: NIECONN_BROKEN), dp_tm_status=3

DpRTmPrepareReq: client address of T92 is 172.20.166.147(172.20.166.147)

***LOG Q04=> DpRTmPrep, NiBufReceive (25076A1051915 92 SAP17A ) [dpxxdisp.c   12455]

RM-T92, U25076, 218     A1051915, SAP17A, 09:58:14, M0, W4, CS15, 2/2

HardCancel request for T92 U25076 M0 received from DISPATCHER

Mon Sep 22 10:28:43 2014

DpRqCheck: mode 0 in status CANCEL***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  92    wp_ca_blk   7       wp_id 16

-IN-- action    SEND_TO_WP        uid  25076   appc_ca_blk -1      type  NOWP

-IN-- new_stat  NO_CHANGE         mode 0     len         8       rq_id 36846

-IN-- req_info  LOGOFF

-IN-- msg_name  -                  

DpRqCheck: mode 0 in status CANCEL***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  92    wp_ca_blk   5       wp_id 16

-IN-- action    SEND_TO_WP        uid  25076   appc_ca_blk -1      type  NOWP

-IN-- new_stat  NO_CHANGE         mode 0     len         8       rq_id 37022

-IN-- req_info  LOGOFF

-IN-- msg_name  -                  

DpRqCheck: mode 0 in status CANCEL***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  92    wp_ca_blk   8       wp_id 16

-IN-- action    SEND_TO_WP        uid  25076   appc_ca_blk -1      type  NOWP

-IN-- new_stat  NO_CHANGE         mode 0     len         8       rq_id 37396

-IN-- req_info  LOGOFF

-IN-- msg_name  -                  

DpRqCheck: mode 0 in status CANCEL***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  92    wp_ca_blk   9       wp_id 16

-IN-- action    SEND_TO_WP        uid  25076   appc_ca_blk -1      type  NOWP

-IN-- new_stat  NO_CHANGE         mode 0     len         8       rq_id 37579

-IN-- req_info  LOGOFF

-IN-- msg_name  -                  

Mon Sep 22 10:37:03 2014

DpRqCheck: mode 1 in status CANCEL***LOG Q0G=> DpRqBadHandle, bad_req ( DIA) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 7063): [dpxxdisp.c   6153]

-IN-- sender_id REMOTE_TERMINAL   tid  98    wp_ca_blk   0       wp_id -1

-IN-- action    SEND_TO_WP        uid  25465   appc_ca_blk -1      type  DIA 

-IN-- new_stat  NO_CHANGE         mode 1     len         353     rq_id 52171

-IN-- msg_name  -                  

Mon Sep 22 10:37:04 2014

*** ERROR => DpRqCheck: T98 in state TM_SLOT_FREE [dpxxdisp.c   8022]

***LOG Q0G=> DpRqBadHandle, bad_req (NOWP) [dpxxdisp.c   6151]

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

-IN-- sender_id DISPATCHER        tid  98    wp_ca_blk   2       wp_id 26

-IN-- action    SEND_TO_WP        uid  25465   appc_ca_blk -1      type  NOWP

-IN-- new_stat  WP_WAIT           mode 2     len         8       rq_id 52173

-IN-- req_info  LOGOFF,CANCELMODE

-IN-- msg_name  -                  

Mon Sep 22 11:33:15 2014

DpSigInt: caught signal 2

DpHalt: shutdown server >tccap32_TCP_32                          < (normal)

DpModState: change server state from ACTIVE to SHUTDOWN

DpHalt: stop work processes

dev_disp.txt.zip

[abhishek_sehgal]

Check if you are able to resolve both server IP from each of them. Maybe there would be DNS problem

[xymanuel]

Hi Dennis,

first, you do not have a connection problem to the DB or to the enqeueue. There will be other entries in the logs like "enqueue not reached" or "DB connection broken, reconnect in progress". The workprocesses will restart automatically if this happens. If the enqueue will not be available, the instance keeps on running forever but you will not be able to work. If the DB is not available, the workprocesses try to reconnect several times before they give up.

From your log i can see, that the dispatcher received a shutdown signal "singal 2 with "normal"

I would say, someone just shut down your instance.

Thats all.

Regards

Manuel

[Former Member]

>>Mon Sep 22 09:06:52 2014

>>SoftCancel request for T71 U24272 M0 received from REMOTE_TERMINAL

this one did request the shutdown of the application server!

regards

Peter

[xymanuel]

Btw. i would say the system did a soft shutdown.

This means s.o. initiated a shutdown and the system will wait, until no one or no work is longer existant on this appserver.

The shutdown can happen a few hours later after you initiated the shutdown.

Regards

Manuel

[former_member211576]

Hi Peter,

  I always appreciate your replies and they really helps me a lot.

If I understand the note 602757 correctly,

1.)

Mon Sep 22 09:06:52 2014

SoftCancel request for T71 U24272 M0 received from REMOTE_TERMINAL

>> This means termination of a user session, ex: User use Ctrl+Alt+Del to endtask SAPGUI.

4.)

Mon Sep 22 11:33:16 2014

SoftCancel request for T115 U26044 M0 received from DISPATCHER

>> This means termination of a disp+work, ex: I saw disp+work became grey and I stopped it and restart again.

[former_member211576]

Hi Manuel,

  Maybe I should redefine my problem.

I saw disp+work became grey in the morning yesterday and I thought it was dead and I restarted it at Sep 22 11:33am.

However, in the afternoon the same problem occurred again, but this time I saw it became from green to grey and back to green again.

So the question is why did disp+work became grey(my colleague said he saw it many times and the application server always became very slow at the same time). I did not find any useful error messages in dev_disp for troubleshooting.

But I am glad to see it works normally today(after restarting).

[former_member211576]

Hi Manuel,

  Maybe I should redefine my problem.

I saw disp+work became grey in the morning yesterday and I thought it was dead and I restarted it at Sep 22 11:33am.

However, in the afternoon the same problem occurred again, but this time I saw it became from green to grey and back to green again.

So the question is why did disp+work became grey(my colleague said he saw it many times and the application server always became very slow at the same time). I did not find any useful error messages in dev_disp for troubleshooting.

But I am glad to see it works normally today(after restarting).

[Former Member]

if just the color flips in SAPMMC and the ABAP Server is still running, you should have a look into sapstart.log, sapstartsrv.log in the work directory as well as into Windows Eventlog (Application and System).

regards

Peter

[divyanshu_srivastava3]

Hi Dennis,

Can you look at the core dump which was generated ?

Also, check sm21 and st22 against this work process number and see if you get the actual cause.

*** ERROR => DpRqBadHandle: BAD REQUEST - Reason: DpRqCheck failed (line 4229): [dpxxdisp.c   6153]

You may also check below note and see if that helps.

1684891 - System log Q0G due to cancelled user sessions

Regards,

[Former Member]

see below error:

*** ERROR => NiIRead: SiRecv failed for hdl 524/sock 1824

looks like some kind of network issues. Do you have CI and DB on same server?

[former_member211576]

First of all, sorry form my poor English.

I have 19 application servers and only 2 application servers died automatically.

To Sunil,

   Yes, ASCS and DB are on the same physical server but it use different virtual hostname.

By the way, CI(a.k.a. DVEBMGS<no>) is on the other server. It is just like a standard DI, nothing in particular.

[Sriram2009]

Hi

Could you check this SAP Notes

1934023 - Application server startup fail with an ICM connection error

157246 - DpRqCheck: T22 in stat TM_SLOT_FREE

BR

SS

[Former Member]

thanks, there was some kind of network issues between your message server and the 2 app servers thats why these two server crashed.

[former_member211576]

Hi Sunil & All,

  I check all notes but I do not find a symptom matched my scenario. I had updated my kernel patch  a few days ago already.

  I check just now and I find a very weird symptom. The disp+work on these two application servers become grey temporary(maybe a few minutes and it becomes green after a few minutes AUTOMATICALLY).

  According to my experience before, if disp+work became grey, it indicated it is dead and it would not become green automatically. I would use niping - long stability test to monitor for a couple days.

[former_member206552]

Good Day Dennis,

have you had a look at this ?

Dispatcher fails (Request (type NOWP) cannot be processed) - Toolbox for IT Groups

Best Regards

Marius

[Sriram2009]

Hi Dennis

Just do the full restart the system and then check once again

BR

SS

[Sriram2009]

Hi

Is this any changes made in the last SAP instance restart?

BR

SS

[former_member211576]

Hi SS,

  Restart is not a good solution and I don't want this occurs over and over again.

The kernel files are the same as other application server's. I need someone to identify the source of the problem.