400Beta2a Trial Feedback (Service Autostart)

[Beaver]

FirstSpot 400 Beta2a Trial

Brand new install.

This has been reproduced on three different brand new builds in my lab although i was using Microsoft Virtual Server 2005 R2 for the testing platform.

Windows 2003 server standard sp1 slipstream.

No Critical updates

Followed readme.rtf and turned off driver signing.

During the install i manually selected to start the dispatcher service automatically.

Finisied the install then restarted the server.

The dispatcher service had been set to autostart and it's current status was starting.

After a short time a pop window tells me that a service had failed to start.

When i check the System Event log there has been an error and the dispatcher service has hung on starting.

But then continues to start later after the other services start all OK

I have applied the PayPal patch.

Everything else i have tested seems to be working ok it's just this ugly error.

Anyway nice product keep up the good work :)

[alan]

Have you used the workaround specified in http://www.patronsoft.com/forum/viewtopic.php?p=3351#3351 (I delete your posting there)?

BTW, the PayPal patch is for beta2 only (beta2a contains the fix already).
_________________
~ Patronsoft Limited ~

[Beaver]

"Have you used the workaround specified in http://www.patronsoft.com/forum/viewtopic.php?p=3351#3351"

Yes tried that one i have tested at 30000 60000 90000 and 100000ms

No Luck

The Exact Error is different from the one described in your link

Event ID 7022
"The Patronsoft FirstSpot Dispatcher service hung on starting."


BTW, the PayPal patch is for beta2 only (beta2a contains the fix already). Thanks

[alan]

Please post your firstspot_gw_srv_[timestamp].log file under FirstSpot\log subdirectory (must be the log file that is generated by a failed FirstSpot auto-start)
_________________
~ Patronsoft Limited ~

[Beaver]

I fixed the problem buy running Windows XP SP2.

Sorry i could not provide further information on Windows 2003 server i have moved on to another project.

Thanks for your help we will buy a copy when you release the new version.

[Beaver]

Here is the log file for the Windows 2003 Error.

I have just completed a new build on a different machine using Windows 2003 Std R2 which is the same as Windows 2003 Std SP1 slipstream.

Could it be my regional settings?

18/02/2006 17:14:16 ** Starting Print Log **
18/02/2006 17:14:16 ** FirstSpot Version (4.0.0 (Beta 2a)) **
18/02/2006 17:14:16 ** Service: Read Session Log
18/02/2006 17:14:16 ** Service: Read DataBase Info
18/02/2006 17:14:16 ** Service: Read BlockICMP_UDP
18/02/2006 17:14:16 ** Service: BLOCK_ICMP Disabled
18/02/2006 17:14:16 ** Service: BLOCK_UDP Enabled
18/02/2006 17:14:16 ** Service: Read Driver Param
18/02/2006 17:14:16 ** Service: Read Global BandWidth Throttle
18/02/2006 17:14:16 ** Service: Read PW Offloading
18/02/2006 17:14:16 ** Service: Read Session Handling
18/02/2006 17:14:16 ** Service: Read Anonymous Login
18/02/2006 17:14:16 ** Service: Read Lisence Path
18/02/2006 17:14:16 ** Service: Read IP
18/02/2006 17:14:16 ** Service: Read Multiple Network Segment
18/02/2006 17:14:16 ** Service: Read Allow Disconnect
18/02/2006 17:14:16 ** Service: Read Allow Disconnect: allow private disconnect[NO][]
18/02/2006 17:14:16 ** Service: Read Allow Disconnect: allow public disconnect[NO][]
18/02/2006 17:14:16 ** Service: Read NIC
18/02/2006 17:14:16 ** Service: Read Allowed Hosts
18/02/2006 17:14:16 ** Service: Read Default Login Page
18/02/2006 17:14:16 ** Service: Read DHCP
18/02/2006 17:14:16 ** Service: Read Skip Nic D/E
18/02/2006 17:14:16 ** Service: Read RADIUS
18/02/2006 17:14:16 ** Service: Read Packet Drop Period
18/02/2006 17:14:16 ** Service: Packet Drop Period [20]
18/02/2006 17:14:16 ** Service: Read SMTP
18/02/2006 17:14:16 ** Service: SMTP Roaming OFF
18/02/2006 17:14:16 ** Service: Read AuthServ
18/02/2006 17:14:16 ** Service: Read Global Data Transfer
18/02/2006 17:14:16 ** Service: Read URL Tracking
18/02/2006 17:14:16 ** Service: URL Tracking OFF
18/02/2006 17:14:16 ** System Info for Verification **
18/02/2006 17:14:16 ** System Info for Verification:Microsoft Windows Server 2003 family
18/02/2006 17:14:16 ** System Info for Verification:Standard Edition
18/02/2006 17:14:16 ** System Info for Verification:{Service Pack 1} (Build 3790)
18/02/2006 17:14:16 ** SUCCESS **
18/02/2006 17:14:16 ** Hardware Info for Verification **
18/02/2006 17:14:16 ** Hardware Info for Verification: Number of processors: {1}
18/02/2006 17:14:16 ** Hardware Info for Verification: Page size: {4096}
18/02/2006 17:14:16 ** Hardware Info for Verification: Processor type: {Alpha]
18/02/2006 17:14:16 ** Hardware Info for Verification: wProcessorLevel: {Intel Pentium Pro, II, III or 4}
18/02/2006 17:14:16 ** Hardware Info for Verification: CPU Hz {799}MHz
18/02/2006 17:14:16 ** Hardware Info for Verification: CPU Name {VIA Samuel 2}
18/02/2006 17:14:16 ** Hardware Info for Verification: CPU Model {x86 Family 6 Model 7 Stepping 3}
18/02/2006 17:14:16 ** Memory Status: Total Physical Memory 247 MBytes
18/02/2006 17:14:16 ** Memory Status: Free Physical Memory 146 MBytes
18/02/2006 17:14:16 ** Memory Status: Total Page File 610 MBytes
18/02/2006 17:14:16 ** Memory Status: Available Page File 497 MBytes
18/02/2006 17:14:17 ** Memory Status: Total Virtual Memory 2047 MBytes
18/02/2006 17:14:17 ** Memory Status: Available Virtual Memory 2002 MBytes
18/02/2006 17:14:17 ** Memory Status: Total Memory Loaded 40 Bytes
18/02/2006 17:14:17 ** Memory Mapping: [C:\Program Files\FirstSpot\log\firstspot_gw_srv_2006.02.18_17.14.15.log]
18/02/2006 17:14:17 ** Reset All Accounts
18/02/2006 17:14:17 ** verifyPublicNicStatus=>
18/02/2006 17:14:17 ** firstspotconOperation2=>
18/02/2006 17:14:17 ** firstspotconOperation2: Connection Name[Local Area Connection]
18/02/2006 17:14:18 ** firstspotconOperation2: Hardware Name Obtained[VIA Rhine II Fast Ethernet Adapter]
18/02/2006 17:14:18 ** firstspotconOperation2: Hardware ID Obtained[PCI\VEN_1106&DEV_3065&SUBSYS_01021106&REV_51\3&61AAA01&0&90]
18/02/2006 17:14:18 ** firstspotconOperation2{STA_PUBLIC_NIC}: Getting Status
18/02/2006 17:14:18 ** firstspotconOperation2{STA_PUBLIC_NIC}: Public NIC started
18/02/2006 17:14:18 ** <=firstspotconOperation2
18/02/2006 17:14:18 ** <=verifyPublicNicStatus
18/02/2006 17:14:18 ** probePublicIP->
18/02/2006 17:14:18 ** probePublicIP: Connection Name[Local Area Connection]
18/02/2006 17:14:18 ** probePublicIP: Hardware Guid Obtained[{894A0F82-DA0B-4896-8F27-BDEF9E9E1153}]
18/02/2006 17:14:18 ** <-probePublicIP
18/02/2006 17:14:18 ** startDemoMode->
18/02/2006 17:14:18 ** <-startDemoMode
18/02/2006 17:14:18 ** writeRedirectPort->
18/02/2006 17:14:19 ** <-writeRedirectPort
18/02/2006 17:14:19 ** validate_SubnetAddr =>
18/02/2006 17:14:19 ** validate_SubnetAddr <=
18/02/2006 17:14:19 ** EnableDisableAssignIPs ->
18/02/2006 17:14:19 ** firstspotconOperation2=>
18/02/2006 17:14:19 ** firstspotconOperation2: Connection Name[Local Area Connection 2]
18/02/2006 17:14:19 ** firstspotconOperation2: Hardware Name Obtained[Intel(R) PRO/100+ PCI Adapter]
18/02/2006 17:14:19 ** firstspotconOperation2: Hardware ID Obtained[PCI\VEN_8086&DEV_1229&SUBSYS_00098086&REV_05\3&61AAA01&0&A0]
18/02/2006 17:14:19 ** firstspotconOperation2{DIS_PRIVATE_NIC}: Disabling
18/02/2006 17:14:24 ** firstspotconOperation2{DIS_PRIVATE_NIC}:Private NIC disabled successfully
18/02/2006 17:14:24 ** <=firstspotconOperation2
18/02/2006 17:14:24 ** EnableDisableAssignIPs: Configuring Private NIC
18/02/2006 17:14:35 ** EnableDisableAssignIPs: Finished Configuring Private NIC
18/02/2006 17:14:35 ** firstspotconOperation2=>
18/02/2006 17:14:35 ** firstspotconOperation2: Hardware ID Obtained[PCI\VEN_8086&DEV_1229&SUBSYS_00098086&REV_05\3&61AAA01&0&A0]
18/02/2006 17:14:35 ** firstspotconOperation2{EN_PRIVATE_NIC}: Enabling
18/02/2006 17:14:39 ** firstspotconOperation2{EN_PRIVATE_NIC}:Private NIC enabled successfully
18/02/2006 17:14:39 ** <=firstspotconOperation2
18/02/2006 17:14:39 ** <- EnableDisableAssignIPs
18/02/2006 17:14:39 ** verifyPrivateNicStatus=>
18/02/2006 17:14:39 ** firstspotconOperation2=>
18/02/2006 17:14:39 ** firstspotconOperation2: Hardware ID Obtained[PCI\VEN_8086&DEV_1229&SUBSYS_00098086&REV_05\3&61AAA01&0&A0]
18/02/2006 17:14:39 ** firstspotconOperation2{STA_PRIVATE_NIC}: Getting Status
18/02/2006 17:14:39 ** firstspotconOperation2{STA_PRIVATE_NIC}: Private NIC started
18/02/2006 17:14:39 ** <=firstspotconOperation2
18/02/2006 17:14:39 ** <=verifyPrivateNicStatus
18/02/2006 17:14:39 entering verify NIC
18/02/2006 17:14:39 verify NIC : Public NIC{{894A0F82-DA0B-4896-8F27-BDEF9E9E1153}}
18/02/2006 17:14:39 verify NIC : Private NIC{{06F08C41-7F61-4FD2-84E3-1DA6E2F4B8D4}}
18/02/2006 17:14:39 IoctlNdisQueryGlobalStats ->
18/02/2006 17:14:39 <- IoctlNdisQueryGlobalStats
18/02/2006 17:14:39 IoctlNdisQueryGlobalStats ->
18/02/2006 17:14:39 <- IoctlNdisQueryGlobalStats
18/02/2006 17:14:39 leaving verify NIC
18/02/2006 17:14:39 IoctlNdisQueryGlobalStats ->
18/02/2006 17:14:39 <- IoctlNdisQueryGlobalStats
18/02/2006 17:14:39 ** GetMacAddress: (mac 00:90:27:24:96:89)
18/02/2006 17:14:39 ** RestartApacheService->
18/02/2006 17:14:39 ** RestartApacheService: restart gracefully
18/02/2006 17:14:41 ** <-RestartApacheService
18/02/2006 17:14:41 ** StopUnusedServices->
18/02/2006 17:14:41 ** StopUnusedServices: SharedAccess
18/02/2006 17:14:41 ** StopUnusedServices: DNS
18/02/2006 17:14:41 ** StopUnusedServices: DHCPServer
18/02/2006 17:14:41 ** <-StopUnusedServices
18/02/2006 17:14:41 ** modifyRRAS ->
18/02/2006 17:14:41 ** resetRRAS ->
18/02/2006 17:14:43 ** resetRRAS: remove private NIC
18/02/2006 17:14:44 ** resetRRAS: add private NIC
18/02/2006 17:14:45 ** <- resetRRAS
18/02/2006 17:14:45 ** modifyRRAS: Configuring
18/02/2006 17:14:47 ** restartRRAS->
18/02/2006 17:14:47 ** restartRRAS: failed the lock
18/02/2006 17:15:17 ** restartRRAS: waiting lock
18/02/2006 17:15:48 ** restartRRAS: waiting lock
18/02/2006 17:16:18 ** restartRRAS: waiting lock
18/02/2006 17:16:48 ** restartRRAS: waiting lock
18/02/2006 17:17:01 ** restartRRAS: OpenService
18/02/2006 17:17:01 ** restartRRAS: Stopping
18/02/2006 17:17:02 ** restartRRAS: starting
18/02/2006 17:17:03 ** <-restartRRAS
18/02/2006 17:17:03 ** <- modifyRRAS
18/02/2006 17:17:03 ** modifyDNS ->
18/02/2006 17:17:03 using DNS 139.130.4.4
18/02/2006 17:17:03 ** WriteBindCfg: bindpath[C:\Program Files\FirstSpot\dns\etc\]
18/02/2006 17:17:03 ** <- modifyDNS
18/02/2006 17:17:06 Multiple Network Segment Count = (0)
18/02/2006 17:17:06 Quit WriteROUTERCfg!
18/02/2006 17:17:07 running trial edition expiration on Mon Mar 20 17:12:49 2006
18/02/2006 17:17:07 ** Service: Read DataBase Info
18/02/2006 17:17:07 <------ batch_fP_RetValue stats : 0.
18/02/2006 17:17:07 no Batch File or Failed the execution
18/02/2006 17:17:07 ** StartServiceThread=>
18/02/2006 17:17:07 ** setdispatcher=>
18/02/2006 17:17:07 ** setdispatcher : SMTP Roaming OFF
18/02/2006 17:17:07 ** setdispatcher : MAC-base session handling
18/02/2006 17:17:07 ** setdispatcher : Private IP(10.20.7.0)
18/02/2006 17:17:07 ** setdispatcher : idle timeout(10)
18/02/2006 17:17:07 ** setdispatcher : driver timeout(1)
18/02/2006 17:17:07 ** setdispatcher : Gateway IP(10.20.7.1)
18/02/2006 17:17:07 ** setdispatcher : Listen Port(5786)
18/02/2006 17:17:07 ** setdispatcher : Auth Port(5788)
18/02/2006 17:17:07 ** setdispatcher : Redirect Port(5790)
18/02/2006 17:17:07 ** setdispatcher : Authenicate IP(10.20.7.1)
18/02/2006 17:17:07 ** setdispatcher : Up Load Limit(-1)
18/02/2006 17:17:07 ** setdispatcher : Down Load Limit(-1)
18/02/2006 17:17:07 ** setdispatcher : Interval(1)
18/02/2006 17:17:07 ** setdispatcher : Drop Period(2)
18/02/2006 17:17:07 ** setdispatcher : PKTInterval(20)
18/02/2006 17:17:07 ** <=setdispatcher
18/02/2006 17:17:07 ** AddPassiveLoginMAC=>
18/02/2006 17:17:07 IoctlNdisQueryGlobalStats ->
18/02/2006 17:17:07 <- IoctlNdisQueryGlobalStats
18/02/2006 17:17:07 ** GetMacAddress: (mac 00:90:27:24:96:89)
18/02/2006 17:17:07 ** AddPassiveLoginMAC: IOCTL_CMD_PL_MAC_RESET SUCCESS
18/02/2006 17:17:07 ** <=AddPassiveLoginMAC
18/02/2006 17:17:07 ** StartServiceThread: setdispatcher Success(1)
18/02/2006 17:17:07 ** EnableDrvBlock: BLOCK_ICMP DISABLED
18/02/2006 17:17:07 ** EnableDrvBlock: IOCTL_CMD_DISABLE_BLOCK_ICMP SUCCESS
18/02/2006 17:17:07 ** EnableDrvBlock: BLOCK_UDP ENABLED
18/02/2006 17:17:07 ** EnableDrvBlock: IOCTL_CMD_ENABLE_BLOCK_UDP SUCCESS
18/02/2006 17:17:07 ** EnableDrvDP: IOCTL_CMD_ENABLE_DEBUG SUCCESS, debug_level=1
18/02/2006 17:17:07 ** EnableDrvDP: IOCTL_CMD_DEBUG_PATH_INIT SUCCESS
18/02/2006 17:17:07 ** InitAllowIPTable: IOCTL_CMD_ALLOWED_IP_INIT SUCCESS
18/02/2006 17:17:07 ** read_client_pass ->
18/02/2006 17:17:07 ** read_client_pass: file name=C:\Program Files\FirstSpot\config.ini, session=0
18/02/2006 17:17:07 ** <- read_client_pass
18/02/2006 17:17:07 ** read_qos_entry ->
18/02/2006 17:17:07 ** <- read_qos_entry
18/02/2006 17:17:07 ** read_port_filter ->
18/02/2006 17:17:07 ** <- read_port_filter
18/02/2006 17:17:07 ** read_acl ->
18/02/2006 17:17:07 ** <- read_acl
18/02/2006 17:17:07 ** indicate_subnetmask: IOCTL_CMD_GET_SUBNETMASK SUCCESS, sm.smask={255.255.255.0}
18/02/2006 17:17:07 ** read_allowed_hosts: {C:\Program Files\FirstSpot\AllowedHostsKeywords.txt}
18/02/2006 17:17:07 ** InitialCaptureThread: ->
18/02/2006 17:17:07 ** <- InitialCaptureThread:
18/02/2006 17:17:07 ** ServiceExecutionThread ->
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {0}={patronsoft.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {1}={search.msn.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {2}={www.paypal.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {3}={www.paypalobjects.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {4}={select.worldpay.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {5}={secure.authorize.net}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {6}={account.authorize.net}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {7}={companion.yahoo.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {8}={toolbar.msn.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {9}={data.alexa.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {10}={www.printspots.com}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {11}={www.printeron.net}
18/02/2006 17:17:07 ** read_allowed_hosts: Allowed Host {12}={google.com}
18/02/2006 17:17:07 ** DeviceNotifyDB=>
18/02/2006 17:17:07 ** DeviceNotifyDBLogin=>
18/02/2006 17:17:07 ** PipeListenThread ->
18/02/2006 17:17:07 ** ObtainBWReportThread ->
18/02/2006 17:17:11 Bandwidth Throttle (Overall Upload Limit:(unlimit)KB/s Overall Download Limit:(unlimit)KB/s)
18/02/2006 17:17:11 ** StartServiceThread: Service Started
18/02/2006 17:17:12 ** AddressThread: Status Code[0]

[alan]

You can ignore this error as FirstSpot is started correctly.

If you want to eliminate this error in the Event Viewer, you need to modify the registry setting. Again, refer to http://www.patronsoft.com/forum/viewtopic.php?p=3351#3351 for details.
_________________
~ Patronsoft Limited ~

[Beaver]

Hi Alan,

Thanks for your reply

Yes i have tried that one i have tested at 30000 60000 90000 and 100000ms

No Luck

The Exact Error is different from the one described in your link

Event ID 7022
"The Patronsoft FirstSpot Dispatcher service hung on starting."

The error not only gets logged in the logs but displays a pop up window stating that "A service failed to start" even if i have not logged in.

Is the Windows Event ID 7022 the same as Event ID 7011?

I have read the link that you posted many times over and fail to see where i am going wrong?

Could you please post exact instructions or registry changes required?

Sorry to be such a problem :)

[alan]

Here is the instruction:

This timeout can be configured on Windows 2000 globally by creating a REG_DWORD registry value named "ServicesPipeTimeout" in milliseconds, under the following registry key.

HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control


If this value is not present, the system assumes a default value of 30000
(30 seconds). This value is read from the registry at system startup, so
you will need to add/modify the value when you install your service and
then it should be honored the next time you reboot.
_________________
~ Patronsoft Limited ~

[Beaver]

Hi Alan,

I have tried this many times over and over for the past two weeks.

i have just tried again using the following settings 60000 80000 100000

Each time i restarted the system i got the same error only it took longer for the pop up windows to show.

Do you have any other settings that i should try?

[alan]

We will do more investigation.

But one more question, does FirstSpot start and function even with the error? Because the log looks correct to us.
_________________
~ Patronsoft Limited ~

[Beaver]

Yes FirstSpot does start and function correctly after the error and pop up window.

FirstSpot work fine after the error.

It's just the pop up window stating that "One or more services failed to start" that really gets me.

I am not worry about the log just the pop up window.

[Beaver]

The is a section from the log posted above.

I noticed that a few minutes pass during these entries relating to RRAS

Is this normal could this have somthing to do with the problem?

I have tested with full USA Regional settings this did not make any difference.

I have tried with the Remote Access Service set for autostart this did not make any difference.


18/02/2006 17:14:47 ** restartRRAS->
18/02/2006 17:14:47 ** restartRRAS: failed the lock
18/02/2006 17:15:17 ** restartRRAS: waiting lock
18/02/2006 17:15:48 ** restartRRAS: waiting lock
18/02/2006 17:16:18 ** restartRRAS: waiting lock
18/02/2006 17:16:48 ** restartRRAS: waiting lock
18/02/2006 17:17:01 ** restartRRAS: OpenService
18/02/2006 17:17:01 ** restartRRAS: Stopping
18/02/2006 17:17:02 ** restartRRAS: starting
18/02/2006 17:17:03 ** <-restartRRAS
18/02/2006 17:17:03 ** <- modifyRRAS

[alan]

As a workaround, you can create a batch file and use Windows Scheduled Tasks instead of Windows Services to autostart. The content of the batch file should be like:

net start DispatcherService
_________________
~ Patronsoft Limited ~

[Beaver]

Thanks!

That worked.

No more errors!