[Search for users] [Overall Top Noters] [List of all Conferences] [Download this site]

Conference azur::mcc

Title:	DECmcc user notes file. Does not replace IPMT.
Notice:	Use IPMT for problems. Newsletter location in note 6187
Moderator:	TAEC::BEROUD

Created:	Mon Aug 21 1989
Last Modified:	Wed Jun 04 1997
Last Successful Update:	Fri Jun 06 1997
Number of topics:	6497
Total number of notes:	27359

997.0. "PROBLEM: accvio in proccessing for mcc_event_put" by COOKIE::KITTELL (Richard - Architected Info Mgmt) Wed May 08 1991 17:05

V1.1 SSB

%SYSTEM-F-ACCVIO, access violation, reason mask=00, virtual address=00000008, PC
=0010927C, PSL=03C00004
break on exception at MCC_EVENT_ERB\ERB_MATCH_ERB\%LINE 2021
DBG> SHOW CALLS 10
 module name     routine name                     line       rel PC    abs PC
*MCC_EVENT_ERB   ERB_MATCH_ERB                    2021      00000050  0010927C
 MCC_EVENT_PRB                                              00000000  00108B83
 MCC_EVENT_CIT                                              00000000  00105C0A
 MCC_EVENT_PUT                                              00000000  000C8DC1

An mcc_event_get with a matching entity spec is pending when the
call to mcc_event_put is made. Other than the accvio, both calls seem to
work, they get success returns and mcc_event_get receives all the proper
info.

T.R	Title	User	Personal Name	Date	Lines
997.1	Looks nasty, but it might be an easy one	TOOK::GUERTIN	I do this for a living -- really	`Wed May 08 1991 17:38`	17
	Something doesn't sound quite right. It appears that the Put code was in the process of matching the event data with the requests. I can't see how the Get would be able to pick up anything since the ACCVIO occured before the match was found. Are you wildcarding any of the mcc_event_get parameters (event codes, partitions, etc.)? Also, it may help if you trace the get and put parts of the event manager: $ define mcc_event_log 1 $ define mcc_event_trace 180 Most of the time when the Event Manager ACCVIOs on the Put side, it is because the mcc_event_get() routine was called with an invalid parameter. Since the mcc_event_get() does not validate parameters, it ends up placing a land mine in the event pool for some Putter to stumble over. -Matt.
997.2	INFO	COOKIE::KITTELL	Richard - Architected Info Mgmt	`Wed May 08 1991 19:11`	37
	RE: .1 Matt, Thanks for the tracing bits. (What is the THUMP!, thread switch?) The problem usually (only) occurs when the event being posted is being waited for by more than one event_get. In particular Notification Services has got an event_get pending, as well as one issued from the command line. The one issued by NS has a time_spec with a duration specified, the one from FCL doesn't, they both wildcard the instance and the event list. The reason the mcc_event_gets are getting data is that the error occurs after the event mgr has processed them, and is looking for more. And from the trace it looks like the event mgr is returning more than one response to the NS. (If anybody wonders what happened to note 998 reporting multiple broadcasts from one event, I deleted it pending resolution of this problem). The tracing from right around the accvio is below, just to give you an idea where it occurs. The whole trace in gory detail will be the next reply. Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request %SYSTEM-F-ACCVIO, access violation, reason mask=00, virtual address=00000008, P\ C=0010927C, PSL=03C00004 Event_Get was Signalled Copying Event Data to user supplied buffers
997.3	Session log including event tracing	COOKIE::KITTELL	Richard - Architected Info Mgmt	`Wed May 08 1991 19:13`	295
	DEFINE BL BranchLibrary TEST1_BRANCH NOTIFY DOMAIN TEST_DOMAIN Events = (Any Events), - Entity List = (BranchLibrary TEST1_BRANCH Task ) %MCC-S-NOTIFSTART, Notify request 1 started DISPLAY NOTIFY Notify requests currently in progress: Entry Status Command ----- ------ ------- 1 Running NOTIFY DOMAIN TEST_DOMAIN Events = (Any Events), Entity List = (BranchLibrary TEST1_BRANCH Task ) DELETE BL CARTR AA0100 Tracing error paths in Event Manager Tracing Event code path in GET Tracing Event code path in PUT Event_Get starting Event_Get processing Partition argument Event_Get Input Arguments ... in_entity = entity [0] wild = NOT_WILD class = 57 id = 2 type = 5 instance = �...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH.. %XAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000 entity [1] wild = INSTANCE_FULL class = 56 Partition = 1 Filter = 184 119 118 88 time_spec = time frame at 2c3d74 hex schedule is NULL scope contains 1 elements element 0 begin is ABSOLUTE: 8-MAY-1991 16:08:33.66 end is ABSOLUTE: 28-NOV-9723 23:59:59.99 periodicity is NULL period_end is NULL Handle context not set up yet Event_Get handle state = MCC_K_HANDLE_FIRST Event_Get building a PRMB for this request Event_Get creating a Heartbeat thread for this request Event_Get setting the Heartbeat thread-id 1000F Event_Get creating TimeStamps Event_Get creating a Maintainer thread for this request Waiting until -> 8-MAY-1991 16:08:36.26 Waiting until -> 8-MAY-1991 16:08:36.26Event_Get setting Maintainer thread-id 10011 Event_Get setting Handle state to MCC_K_HANDLE_MORE Going to wait for the event now... Start_time = 8-MAY-1991 16:08:33.66 End_time = 28-NOV-9723 23:59:59.99 FINAL wait time -> 28-NOV-9723 23:59:59.99 BranchLibrary DEC:.CXN.S.DBS-AIM.MCC.RSK.TEST1_BRANCH Cartridge AA0100 AT 8-MAY-1991 16:08:37 Entity deleted successfully. CREATE BL CARTR AA0100 TYPE = TA90 BranchLibrary DEC:.CXN.S.DBS-AIM.MCC.RSK.TEST1_BRANCH Cartridge AA0100 AT 8-MAY-1991 16:08:39 Entity successfully created. BIND BL CARTR AA0100 COMP NAME = AA0101, CELL = 3, STATION = ANY BranchLibrary DEC:.CXN.S.DBS-AIM.MCC.RSK.TEST1_BRANCH Cartridge AA0100 AT 8-MAY-1991 16:08:50 Bind Started, Reference is 8 GETEVENT BL TASK * ANY EVENTS Event_Get starting Event_Get processing Partition argument Event_Get Input Arguments ... in_entity = entity [0] wild = NOT_WILD class = 57 id = 2 type = 5 instance = �...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH.. %XAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000 entity [1] wild = INSTANCE_FULL class = 56 Partition = 1 Filter = MCC_K_NULL_PTR time_spec = MCC_K_NULL_PTR Handle context not set up yet Event_Get handle state = MCC_K_HANDLE_FIRST Event_Get building a PRMB for this request Event_Get creating a Heartbeat thread for this request Event_Get setting the Heartbeat thread-id 10017 Event_Get creating TimeStamps Event_Get requesting NEXT event Going to wait for the event now... THUMP! Event_Put starting Event_Put processing Partition argument Event_Put Input Arguments ... p_ent_spec = entity [0] wild = NOT_WILD class = 57 id = 2 type = 5 instance = �...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH.. THUMP! %XAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000 entity [1] wild = NOT_WILD class = 56 id = 181 type = 35 instance = .... %X08000000 Partition = 1 Event Code = 184 Event Data = Dump of MCC Descriptor reveals: mcc_w_maxstrlen = 1024 mcc_w_curlen = 178 mcc_b_flags = 0 mcc_b_ver = 1 mcc_l_id = 1 mcc_l_dt = MCC_K_DT_ILV mcc_a_pointer = �..��.R..��.8..�.).......Bind AA0100 into AA0101�.O..g...I.....9.......;�...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH..�........6..........AA0100..7.Normal Completion %XA18200AEBF81528200A8BF81388200A29F290200858219021742696E642041413031303020696E746F20414130313031BF814F820067A0820049810101820139830102840105853BAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000A1820016810101820136830102840104850801064141303130309F8137114E6F726D616C20436F6D706C6574696F6E mcc_a_link = MCC_K_NULL_PTR Timestamp = 8-MAY-1991 16:09:56.71 Event_Put getting current time Event_Put converting user supplied time into BAT Event_Put building an EDS structure to store Event Data Event_Put creating an AHS Event_Put Locking Subscriber structures Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber found Request for NEXT Event Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request Event_Put Subscriber Handle state = MCC_K_HANDLE_MORE Event_Put Subscriber Locking RMBs Event_Put Subscriber matching Request Start Time of 8-MAY-1991 16:08:33.66 Event_Put Subscriber matching Request End Time of 28-NOV-9723 23:59:59.99 Event_Put Subscriber found Request with matching time range Event_Put Subscriber referencing Event Data Event_Put Subscriber building a Event Data Queue Element Event_Put Subscriber sending an Event to a Requestor Event_Put Subscriber Unlocking RMBs Event_Put Subscriber searching for first(/next) matching request %SYSTEM-F-ACCVIO, access violation, reason mask=00, virtual address=00000008, PC=0010927C, PSL=03C00004 Event_Get was Signalled Copying Event Data to user supplied buffers Event_Get converting time to supplied time type Event_Get deleting global event data Event_Get performing general clean up THUMP! Event_Get was Signalled Copying Event Data to user supplied buffers Event_Get converting time to supplied time type Event_Get deleting global event data Event_Get performing general clean up Event_Get Output Arguments ... Context Ident = 135ACE Next RMB = 468200, Prev RMB = 4617F0 PRB List = 467E30, HEAD_EDQ = 465FE0 PRB List = 467E30, HEAD_EDQ = 465FE0Failed to dequeue event: %MCC-E-NOMOREVT, no more events in event queue Event_Get Output Arguments ... Handle context not set up yet out_entity = entity [0] wild = NOT_WILD class = 57 id = 2 type = 5 instance = �...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH.. %XAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000 SOI start = 8-MAY-1991 16:08:33.66 SOI end = 28-NOV-9723 23:59:59.99 TIME_STAMP = 8-MAY-1991 23:09:36.30 Heartbeat Thrid = 0, Timeout Thrid = 0 FLAGS: Frozen = 0, Delete = 0, Next = 0 out_entity = timestamp = 8-MAY-1991 16:09:56.71 Event Code = 184 Event Data = Event_Get completed entity [1] wild = NOT_WILD class = 56 id = 181 type = 35 instance = .... %X08000000 timestamp = 8-MAY-1991 16:09:56.71 Event Code = 184 Event Data = Dump of MCC Descriptor reveals: mcc_w_maxstrlen = 1024 mcc_w_curlen = 178 mcc_b_flags = 0 mcc_b_ver = 1 mcc_l_id = 1 mcc_l_dt = MCC_K_DT_ILV mcc_a_pointer = �..��.R..��.8..�.).......Bind AA0100 into AA0101�.O..g...I.....9.......;�...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH..�........6..........AA0100..7.Normal Completion %XA18200AEBF81528200A8BF81388200A29F290200858219021742696E642041413031303020696E746F20414130313031BF814F820067A0820049810101820139830102840105853BAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000A1820016810101820136830102840104850801064141303130309F8137114E6F726D616C20436F6D706C6574696F6E mcc_a_link = MCC_K_NULL_PTR Event_Get completed BranchLibrary DEC:.CXN.S.DBS-AIM.MCC.RSK.TEST1_BRANCH Task 8 AT 8-MAY-1991 16:09:56 Any Event Task Completed Directive = Bind Name = "Bind AA0100 into AA0101" Target = BranchLibrary DEC:.CXN.S.DBS-AIM.MCC.RSK.TEST1_BRANC H Cartridge AA0100 Completion Status = "Normal Completion" %MCC-S-VERIFYEXIT, exiting command procedure DISK$AIM1:[KITTELL.SCRATCH]A.COM;40 EXIT Event_Get starting Event_Get processing Partition argument Event_Get Input Arguments ... in_entity = entity [0] wild = NOT_WILD class = 57 id = 2 type = 5 instance = �...�..��oV�..+...CXN..S..DBS-AIM..MCC..RSK..TEST1_BRANCH.. %XAA000400DE11A0AAF96F56DE8E002B00010343584E01015301074442532D41494D01034D4343010352534B010C54455354315F4252414E43480000 entity [1] wild = INSTANCE_FULL class = 56 Partition = 1 Filter = 184 119 118 88 Filter = 184 119 118 88Maintainer Thread was alerted during Timer Wait: %MCC-E-ALERT_TERMREQ, thread termination requested time_spec = time frame at 2c3d74 hex schedule is NULL scope contains 1 elements element 0 begin is ABSOLUTE: 8-MAY-1991 16:08:33.66 end is ABSOLUTE: 28-NOV-9723 23:59:59.99 periodicity is NULL period_end is NULL Context Ident = 135ACE Next RMB = 0, Prev RMB = 4617F0 Next RMB = 0, Prev RMB = 4617F0THUMP! PRB List = 467E30, HEAD_EDQ = 465FE0 SOI start = 8-MAY-1991 16:08:33.66 SOI end = 28-NOV-9723 23:59:59.99 TIME_STAMP = 8-MAY-1991 23:09:36.30 Heartbeat Thrid = 0, Timeout Thrid = 0 FLAGS: Frozen = 0, Delete = 0, Next = 0 Event_Get handle state = MCC_K_HANDLE_MORE Going to wait for the event now... EDQ_DEQW_SUBSCR_EVENT found alert termination request Event_Get was Signalled Get Event was Alerted $ EXIT
997.4	We (the MCC Kernel team) need to investigate further	TOOK::GUERTIN	I do this for a living -- really	`Thu May 09 1991 09:53`	23
	Richard, Thanks for the tracing information. It shows that something is going wrong on the Get side. The Putter appears to be finding an invalid request structure in the event pool. I don't think it's anything you are doing, although some things don't make sense to me (for example, partition 1 is the Identifiers partition, which is an attribute partition, not an event partiton). On the other hand, looking at the source code, I don't see a way of getting the ACCVIO you are seeing without a memory clobber/corruption coming in from another thread. Were you doing the Putting and Getting from a single process? Have you tried running MCC from two separate processes, and going Gets and Puts from each? Also, have you tried specifying all of the events explicitly, instead of wildcarding events? Have you tried making the requests in the reverse order? Unfortunately, there does not appear to be simple answer to this one. By the way, the THUMP! is generated by the heartbeat thread which periodicly updates a timestamp in the request structures to tell the Putters that the Getter is still active. -Matt.
997.5	May have been inconsistent event filter arg	COOKIE::KITTELL	Richard - Architected Info Mgmt	`Thu May 09 1991 12:15`	32
	RE: .4 > doing, although some things don't make sense to me (for example, > partition 1 is the Identifiers partition, which is an attribute > partition, not an event partiton). On the other hand, looking at the Matt, That was my initial guess at a partition number before I know what their strategic significance was. It will change to one of the two everyone else is using before we ship. For the moment, as long as getter and putter use the same partition it should work. New data! After reading your initial response I went looking for ways the getter could be cheating, and I think I found something. I noticed that when the time_spec with duration was specified in the call from NS, I was processing the event ids argument in each call, instead of doing it once and stashing the event filter in the context block. Hence the mcc_event_get call would have gotten a different address for the event id array each time it was called. It would have been a valid array, but a different one each time. If mcc_event_get was stashing the filter pointer and using it when called subsequently, it would be using a pointer that was now invalid. After standing in the corner for an hour with the "MCC Dunce" cap on, :-) I fixed the GetEvent entry point to stash the event filter data in the context block so its address wouldn't change. No more accvios! Trouble is, I've worked on other parts of the AM in the interim so it is hard to say conclusively which change made the problem go away.