Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[🐛 Bug]: invalid session id after upgrading to 4.15 (helm-charts on k8s) #2039

Closed
cr-liorholtzman opened this issue Nov 30, 2023 · 26 comments

Comments

@cr-liorholtzman
Copy link

cr-liorholtzman commented Nov 30, 2023

What happened?

After upgrading from 4.10 (chart version 19.0) to 4.15 (chart version 0.25.1) I started to get the following error that fails almost all UI tests - invalid session id

We run on a k8s cluster in GKE with KEDA installed (version 2.12.0).

Command used to start Selenium Grid with Docker (or Kubernetes)

"helm install $NAMESPACE docker-selenium/$NAMESPACE --namespace $NAMESPACE -f $VALUES_FILE  --version 0.25.1 --set firefoxNode.enabled=false --set edgeNode.enabled=false"

Relevant log output

ERROR 09:17:32 invalid session id
Build info: version: '4.15.0', revision: '1d14b5521b'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.107+', java.version: '11.0.18'
Driver info: org.openqa.selenium.remote.RemoteWebDriver$ByteBuddy$VVNEx1FD$ByteBuddy$vm8ptKIM
Command: [bd31f7a5d3533de2aa1190d8ffc54ea5, findElement {using=id, value=siem-alerts-ui-module}]
Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.159, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:44949}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://XXXX..., se:cdpVersion: 119.0.6045.159, se:name: SuspiciousEventsTest.valida..., se:vnc: wss://XXXX..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.147:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}
Session ID: bd31f7a5d3533de2aa1190d8ffc54ea5
org.openqa.selenium.NoSuchSessionException: invalid session id
Build info: version: '4.15.0', revision: '1d14b5521b'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.107+', java.version: '11.0.18'
Driver info: org.openqa.selenium.remote.RemoteWebDriver$ByteBuddy$VVNEx1FD$ByteBuddy$vm8ptKIM
Command: [bd31f7a5d3533de2aa1190d8ffc54ea5, findElement {using=id, value=siem-alerts-ui-module}]
Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.159, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:44949}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://XXXX..., se:cdpVersion: 119.0.6045.159, se:name: SuspiciousEventsTest.valida..., se:vnc: wss://XXXX..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.147:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}
Session ID: bd31f7a5d3533de2aa1190d8ffc54ea5
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
	at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.createException(W3CHttpResponseCodec.java:200)
	at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:133)
	at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:52)
	at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:191)
	at org.openqa.selenium.remote.TracedCommandExecutor.execute(TracedCommandExecutor.java:51)
	at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:607)
	at org.openqa.selenium.remote.ElementLocation$ElementFinder$2.findElement(ElementLocation.java:165)
	at org.openqa.selenium.remote.ElementLocation.findElement(ElementLocation.java:66)
	at org.openqa.selenium.remote.RemoteWebDriver.findElement(RemoteWebDriver.java:364)
	at org.openqa.selenium.remote.RemoteWebDriver.findElement(RemoteWebDriver.java:358)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.openqa.selenium.support.decorators.WebDriverDecorator.call(WebDriverDecorator.java:249)
	at org.openqa.selenium.support.decorators.DefaultDecorated.call(DefaultDecorated.java:48)
	at org.openqa.selenium.support.decorators.WebDriverDecorator.lambda$createProxy$2(WebDriverDecorator.java:321)
	at net.bytebuddy.renamed.java.lang.Object$ByteBuddy$NMIXA2ko.findElement(Unknown Source)
	at org.openqa.selenium.support.ui.ExpectedConditions$7.apply(ExpectedConditions.java:194)
	at org.openqa.selenium.support.ui.ExpectedConditions$7.apply(ExpectedConditions.java:190)
	at org.openqa.selenium.support.ui.FluentWait.until(FluentWait.java:204)
	at XXXX.infra.ActionBot.getVisibleElement(ActionBot.java:100)
	at XXXX.infra.ActionBot.getShadowRoot(ActionBot.java:397)

Operating System

gke

Docker Selenium version (tag or chart version)

4.15.0-20231129

Copy link

@cr-liorholtzman, thank you for creating this issue. We will troubleshoot it as soon as we can.


Info for maintainers

Triage this issue by using labels.

If information is missing, add a helpful comment and then I-issue-template label.

If the issue is a question, add the I-question label.

If the issue is valid but there is no time to troubleshoot it, consider adding the help wanted label.

If the issue requires changes or fixes from an external project (e.g., ChromeDriver, GeckoDriver, MSEdgeDriver, W3C), add the applicable G-* label, and it will provide the correct link and auto-close the issue.

After troubleshooting the issue, please add the R-awaiting answer label.

Thank you!

@cr-liorholtzman
Copy link
Author

This is my values file:

global:
  seleniumGrid:
    # Image tag for all selenium components
    imageTag: 4.15.0-20231129
    # Image tag for browser's nodes
    nodesImageTag: 4.15.0-20231129
    # Pull secret for all components, can be overridden individually
    imagePullSecret: ""

basicAuth:
  # Enable or disable basic auth
  enabled: false
  # Username for basic auth
  username: admin
  # Password for basic auth
  password: admin

# Deploy Router, Distributor, EventBus, SessionMap and Nodes separately
isolateComponents: true

# Service Account for all components
serviceAccount:
  create: false
  name: "default"
  annotations: {}
  #  eks.amazonaws.com/role-arn: "arn:aws:iam::12345678:role/video-bucket-permissions"
# Configure the ingress resource to access the Grid installation.

ingress:
  # Enable or disable ingress resource
  enabled: true
  # Name of ingress class to select which controller will implement ingress resource
  className: "nginx"
  # Custom annotations for ingress resource
  annotations: {}
  # Default host for the ingress resource
  hostname: XXXXX
  # Default host path for the ingress resource
  path: /
  # TLS backend configuration for ingress resource
  tls:
    - hosts:
      secretName: ca-tls

# ConfigMap that contains SE_EVENT_BUS_HOST, SE_EVENT_BUS_PUBLISH_PORT and SE_EVENT_BUS_SUBSCRIBE_PORT variables
busConfigMap:
  # Name of the configmap
  name: selenium-event-bus-config
  # Custom annotations for configmap
  annotations: {}

# ConfigMap that contains common environment variables for browser nodes
nodeConfigMap:
  name: selenium-node-config
  # Custom annotations for configmap
  annotations: {}

# Configuration for isolated components (applied only if `isolateComponents: true`)
components:

  # Configuration for router component
  router:
    # Router image name
    imageName: selenium/router
    # Router image tag (this overwrites global.seleniumGrid.imageTag parameter)
    # imageTag: 4.10.0-20230607

    # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
    imagePullPolicy: IfNotPresent
    # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
    imagePullSecret: ""

    # Custom annotations for router pods
    annotations: {}
    # Router port
    port: 4444
    # Liveness probe settings
    livenessProbe:
      enabled: true
      path: /readyz
      initialDelaySeconds: 10
      failureThreshold: 10
      timeoutSeconds: 10
      periodSeconds: 10
      successThreshold: 1
    # Readiness probe settings
    readinessProbe:
      enabled: true
      path: /readyz
      initialDelaySeconds: 12
      failureThreshold: 10
      timeoutSeconds: 10
      periodSeconds: 10
      successThreshold: 1
    # Resources for router container
    resources: {}
    # SecurityContext for router container
    securityContext: {}
    # Kubernetes service type (see https://kubernetes.io/docs/concepts/services-networking/service/#publishing-services-service-types)
    serviceType: ClusterIP
    # Set specific loadBalancerIP when serviceType is LoadBalancer (see https://kubernetes.io/docs/concepts/services-networking/service/#loadbalancer)
    loadBalancerIP: ""
    # Custom annotations for router service
    serviceAnnotations: {}
    # Tolerations for router pods
    tolerations:
      - key: "app"
        operator: "Equal"
        value: "selenium"
        effect: "NoSchedule"
    # Node selector for selenium-hub pods
    nodeSelector:
      app: "selenium"
    # Priority class name for router pods
    priorityClassName: ""

  # Configuration for distributor component
  distributor:
    # Distributor image name
    imageName: selenium/distributor
    # Distributor image tag (this overwrites global.seleniumGrid.imageTag parameter)
    # imageTag: 4.10.0-20230607

    # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
    imagePullPolicy: IfNotPresent
    # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
    imagePullSecret: ""

    # Custom annotations for Distributor pods
    annotations: {}
    # Distributor port
    port: 5553
    # Resources for Distributor container
    resources: {}
    # SecurityContext for Distributor container
    securityContext: {}
    # Kubernetes service type (see https://kubernetes.io/docs/concepts/services-networking/service/#publishing-services-service-types)
    serviceType: ClusterIP
    # Custom annotations for Distributor service
    serviceAnnotations: {}
    # Tolerations for Distributor pods
    tolerations:
      - key: "app"
        operator: "Equal"
        value: "selenium"
        effect: "NoSchedule"
    # Node selector for selenium-hub pods
    nodeSelector:
      app: "selenium"
    #
    # Priority class name for Distributor pods
    priorityClassName: ""

  # Configuration for Event Bus component
  eventBus:
    # Event Bus image name
    imageName: selenium/event-bus
    # Event Bus image tag (this overwrites global.seleniumGrid.imageTag parameter)
    # imageTag: 4.10.0-20230607

    # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
    imagePullPolicy: IfNotPresent
    # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
    imagePullSecret: ""

    # Custom annotations for Event Bus pods
    annotations: {}
    # Event Bus port
    port: 5557
    # Port where events are published
    publishPort: 4442
    # Port where to subscribe for events
    subscribePort: 4443
    # Resources for event-bus container
    resources: {}
    # SecurityContext for event-bus container
    securityContext: {}
    # Kubernetes service type (see https://kubernetes.io/docs/concepts/services-networking/service/#publishing-services-service-types)
    serviceType: ClusterIP
    # Custom annotations for Event Bus service
    serviceAnnotations: {}
    tolerations:
      - key: "app"
        operator: "Equal"
        value: "selenium"
        effect: "NoSchedule"
    # Node selector for selenium-hub pods
    nodeSelector:
      app: "selenium"
    #
    # Priority class name for Event Bus pods
    priorityClassName: ""

  # Configuration for Session Map component
  sessionMap:
    # Session Map image name
    imageName: selenium/sessions
    # Session Map image tag (this overwrites global.seleniumGrid.imageTag parameter)
    # imageTag: 4.10.0-20230607

    # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
    imagePullPolicy: IfNotPresent
    # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
    imagePullSecret: ""

    # Custom annotations for Session Map pods
    annotations: {}
    port: 5556
    # Resources for Session Map container
    resources: {}
    # SecurityContext for Session Map container
    securityContext: {}
    # Kubernetes service type (see https://kubernetes.io/docs/concepts/services-networking/service/#publishing-services-service-types)
    serviceType: ClusterIP
    # Custom annotations for Session Map service
    serviceAnnotations: {}
    # Tolerations for Session Map pods
    tolerations:
      - key: "app"
        operator: "Equal"
        value: "selenium"
        effect: "NoSchedule"
    # Node selector for selenium-hub pods
    nodeSelector:
      app: "selenium"
    #
    # Priority class name for Session Map pods
    priorityClassName: ""

  # Configuration for Session Queue component
  sessionQueue:
    # Session Queue image name
    imageName: selenium/session-queue
    # Session Queue image tag (this overwrites global.seleniumGrid.imageTag parameter)
    # imageTag: 4.10.0-20230607

    # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
    imagePullPolicy: IfNotPresent
    # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
    imagePullSecret: ""

    # Custom annotations for Session Queue pods
    annotations: {}
    port: 5559
    # Resources for Session Queue container
    resources: {}
    # SecurityContext for Session Queue container
    securityContext: {}
    # Kubernetes service type (see https://kubernetes.io/docs/concepts/services-networking/service/#publishing-services-service-types)
    serviceType: ClusterIP
    # Custom annotations for Session Queue service
    serviceAnnotations: {}
    # Tolerations for Session Queue pods
    tolerations:
      - key: "app"
        operator: "Equal"
        value: "selenium"
        effect: "NoSchedule"
    # Node selector for selenium-hub pods
    nodeSelector:
      app: "selenium"
    #
    # Priority class name for Session Queue pods
    priorityClassName: ""

  # Custom sub path for all components
  subPath: /

  # Custom environment variables for all components
  extraEnvironmentVariables:
  # - name: SE_JAVA_OPTS
  #   value: "-Xmx512m"
  # - name:
  #   valueFrom:
  #     secretKeyRef:
  #       name: secret-name
  #       key: secret-key

  # Custom environment variables by sourcing entire configMap, Secret, etc. for all components
  extraEnvFrom:
  # - configMapRef:
  #   name: proxy-settings
  # - secretRef:
  #   name: mysecret

# Configuration for selenium hub deployment (applied only if `isolateComponents: false`)

# Keda scaled object configuration
autoscaling:
  # Enable autoscaling. Implies installing KEDA
  enabled: false
  # Enable autoscaling without automatically installing KEDA
  enableWithExistingKEDA: yes
  # Which typ of KEDA scaling to use: job or deployment
  scalingType: job
  # Annotations for KEDA resources: ScaledObject and ScaledJob
  annotations:
    helm.sh/hook: post-install,post-upgrade
  # Options for KEDA scaled resources (keep only common options used for both ScaledJob and ScaledObject)
  scaledOptions:
    minReplicaCount: 0
    maxReplicaCount: 30
    pollingInterval: 10
  # Options for KEDA ScaledJobs
  scaledJobOptions:
    successfulJobsHistoryLimit: 0
    failedJobsHistoryLimit: 0
    pollingInterval: 10
    scalingStrategy:
      strategy: accurate
    jobTargetRef:
      parallelism: 1
      completions: 1
      backoffLimit: 0
  deregisterLifecycle:
    preStop:
      exec:
        command:
          - bash
          - -c
          - |
            curl -X POST 127.0.0.1:5555/se/grid/node/drain --header 'X-REGISTRATION-SECRET;' && \
            while curl 127.0.0.1:5555/status; do sleep 1; done;


# Configuration for firefox nodes
firefoxNode:
  # Enable firefox nodes
  enabled: false

# Configuration for chrome nodes
chromeNode:
  # Enable chrome nodes
  enabled: true

  # NOTE: Only used when autoscaling.enabled is false
  # Enable creation of Deployment
  # true (default) - if you want long living pods
  # false - for provisioning your own custom type such as Jobs
  deploymentEnabled: false

  # Number of chrome nodes
  replicas: 0
  # Image of chrome nodes
  imageName: selenium/node-chrome
  # Image of chrome nodes (this overwrites global.seleniumGrid.nodesImageTag)
  # imageTag: 4.10.0-20230607
  # Image pull policy (see https://kubernetes.io/docs/concepts/containers/images/#updating-images)
  imagePullPolicy: IfNotPresent
  # Image pull secret (see https://kubernetes.io/docs/tasks/configure-pod-container/pull-image-private-registry/)
  imagePullSecret: ""

  # Port list to enable on container
  ports:
    - 5555
  # Selenium port (spec.ports[0].targetPort in kubernetes service)
  seleniumPort: 5900
  # Selenium port exposed in service (spec.ports[0].port in kubernetes service)
  seleniumServicePort: 6900
  # Annotations for chrome-node pods
  annotations: {}
  # Labels for chrome-node pods
  labels: {}
  # Resources for chrome-node container
  resources:
    requests:
      memory: "1Gi"
      cpu: "1"
    limits:
      memory: "1Gi"
      cpu: "1"
  # SecurityContext for chrome-node container
  securityContext: {}
  # Tolerations for chrome-node pods
  tolerations:
    - key: "app"
      operator: "Equal"
      value: "selenium"
      effect: "NoSchedule"
    # Node selector for selenium-hub pods
  nodeSelector:
    app: "selenium"
    #
  # Custom host aliases for chrome nodes
  hostAliases:
  # - ip: "198.51.100.0"
  #   hostnames:
  #     - "example.com"
  #     - "example.net"
  # - ip: "203.0.113.0"
  #   hostnames:
  #     - "example.org"
  # Custom environment variables for chrome nodes
  extraEnvironmentVariables:
    - name: SE_NODE_OVERRIDE_MAX_SESSIONS
      value: "false"
    - name: SE_NODE_MAX_SESSIONS
      value: "1"
    - name: SE_NODE_GRID_URL
      value: "XXXX"
    - name: SE_VNC_NO_PASSWORD
      value: "1"
    - name: SE_SCREEN_WIDTH
      value: "1920"
    - name: SE_SCREEN_HEIGHT
      value: "1080"
  # - name:
  #   valueFrom:
  #     secretKeyRef:
  #       name: secret-name
  #       key: secret-key
  # Custom environment variables by sourcing entire configMap, Secret, etc. for chrome nodes
  extraEnvFrom:
  # - configMapRef:
  #   name: proxy-settings
  # - secretRef:
  #   name: mysecret
  # Service configuration
  service:
    # Create a service for node
    enabled: true
    # Service type
    type: "ClusterIP"
    # Custom annotations for service
    annotations: {}
  # Size limit for DSH volume mounted in container (if not set, default is "1Gi")
  dshmVolumeSizeLimit: 1Gi
  # Priority class name for chrome-node pods
  priorityClassName: ""

  # Wait for pod startup
  startupProbe:
    httpGet:
      path: /status
      port: 5555
    failureThreshold: 120
  # periodSeconds: 5
  # Time to wait for pod termination
  terminationGracePeriodSeconds: 30
  # Allow pod correctly shutdown
  lifecycle:
    preStop:
      exec:
        command:
          - bash
          - -c
          - |
            curl -X POST 127.0.0.1:5555/se/grid/node/drain --header 'X-REGISTRATION-SECRET;' && \
            while curl 127.0.0.1:5555/status; do sleep 1; done

  extraVolumeMounts: []
  # - name: selenium-mount
  #   mountPath: /data/screenshot/

  extraVolumes: []
  # - name: selenium-mount
  #   persistentVolumeClaim:
  #     claimName: selenium-pvc

  hpa:
    url: '{{ include "seleniumGrid.graphqlURL" . }}'
    browserName: chrome
    # browserVersion: '91.0' # Optional. Only required when supporting multiple versions of browser in your Selenium Grid.
    unsafeSsl: 'true' # Optional


# Custom labels for k8s resources
customLabels: {}

@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Nov 30, 2023

The router logs is also full of these:

`18:15:18.613 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to execute request for an existing session: null
18:15:18.613 WARN [SeleniumSpanExporter$1.lambda$export$1] - java.lang.NullPointerException

18:15:18.614 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "d4d17e63ff7098658e7649136a93a0fe","eventTime": 1701281718613089014,"eventName": "exception","attributes": {"exception.message": "Unable to execute request for an existing session: null","exception.stacktrace": "java.lang.NullPointerException\n","exception.type": "java.lang.NullPointerException","http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.router.HandleSession","http.host": "selenium-dev-keda.eng.cybereason.net","http.method": "POST","http.request_content_length": "142","http.scheme": "HTTP","http.target": "\u002fsession\u002f0217c9741ddf4eb55223dbdf0c9bf872\u002fcookie","http.user_agent": "selenium\u002f4.10.0 (java unix)","session.id": "0217c9741ddf4eb55223dbdf0c9bf872"}}

18:16:18.599 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to execute request for an existing session: null
18:16:18.600 WARN [SeleniumSpanExporter$1.lambda$export$1] - java.lang.NullPointerException

18:16:18.600 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "64d5ae1f729481a859f8132c4d7d5c04","eventTime": 1701281778599005182,"eventName": "exception","attributes": {"exception.message": "Unable to execute request for an existing session: null","exception.stacktrace": "java.lang.NullPointerException\n","exception.type": "java.lang.NullPointerException","http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.router.HandleSession","http.host": "selenium-dev-keda.eng.cybereason.net","http.method": "GET","http.scheme": "HTTP","http.target": "\u002fsession\u002f0217c9741ddf4eb55223dbdf0c9bf872\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)","session.id": "0217c9741ddf4eb55223dbdf0c9bf872"}}

21:50:44.421 WARN [ProxyWebsocketsIntoGrid$ForwardingListener.onError] - Error proxying websocket command
java.io.IOException: Connection reset by peer
	at java.base/sun.nio.ch.FileDispatcherImpl.read0(Native Method)
	at java.base/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
	at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276)
	at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:245)
	at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:223)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:356)
	at java.net.http/jdk.internal.net.http.SocketTube.readAvailable(SocketTube.java:1153)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:821)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:175)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:271)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:224)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:763)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:941)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:245)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:957)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:912)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:912)`

@VietND96
Copy link
Member

VietND96 commented Dec 1, 2023

Hi @cr-liorholtzman, the same YAML that you used, can you have a try with chart version 0.25.3?
Look around I saw one comment had similar error SeleniumHQ/selenium#13091 (comment)

@cr-liorholtzman
Copy link
Author

@VietND96 any idea why I'm not able to pull the image in the 0.25.3 chart?

Warning Failed 9s (x3 over 52s) kubelet Failed to pull image "selenium/selenium/session-queue:4.15.0-20231129": rpc error: code = Unknown desc = failed to pull and unpack image "docker.io/selenium/selenium/session-queue:4.15.0-20231129": failed to resolve reference "docker.io/selenium/selenium/session-queue:4.15.0-20231129": pull access denied, repository does not exist or may require authorization: server message: insufficient_scope: authorization failed

@VietND96
Copy link
Member

VietND96 commented Dec 3, 2023

Hi @cr-liorholtzman, it is due to feature was added recently in 0.25.3. The imageName: selenium/hub is split to 2 parts are imageRegistry: selenium and imageName: hub
The chart README is updated accordingly, or you can refer to comment on #2035 (comment)
I see your YAML file shared above should be updated.
Also, can you try a practice that your custom YAML file should keep override values only, for remaining no different helm will refer to default chart values. You can refer to some override YAML that we defined https://github.com/SeleniumHQ/docker-selenium/tree/trunk/tests/charts/ci

@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Dec 3, 2023

@VietND96 Thanks made the changes and update to 0.25.3, but still getting the same errors :/
org.openqa.selenium.NoSuchSessionException: invalid session id

Everything is ok once I revert back to 4.10 (chart 0.19)

@VietND96
Copy link
Member

VietND96 commented Dec 3, 2023

One thing I saw in router logs
"http.user_agent": "selenium\u002f4.10.0 (java unix)","session.id": "0217c9741ddf4eb55223dbdf0c9bf872"}}
4.10 is present in logs while the server is 4.15. Can you check which selenium client version is used in your test fwk? Can you try an update with both client and server in the same version?

@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Dec 3, 2023

Yea it's because I switched the selenium version in the pom.xml to test both versions in the client as well, issue was happening with both clients version (while the hub version stayed the same - 4.15)

`WARN  09:55:02 invalid session id
Build info: version: '4.15.0', revision: '1d14b5521b'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.107+', java.version: '11.0.18'
Driver info: org.openqa.selenium.remote.RemoteWebDriver$ByteBuddy$TNt2175f$ByteBuddy$UKHUkDbQ
Command: [fd66c7319b211af051c976b5ae7401c0, getTitle {}]
Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:38047}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.54:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}
Session ID: fd66c7319b211af051c976b5ae7401c0
org.openqa.selenium.NoSuchSessionException: invalid session id
Build info: version: '4.15.0', revision: '1d14b5521b'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.107+', java.version: '11.0.18'
Driver info: org.openqa.selenium.remote.RemoteWebDriver$ByteBuddy$TNt2175f$ByteBuddy$UKHUkDbQ
Command: [fd66c7319b211af051c976b5ae7401c0, getTitle {}]

@VietND96
Copy link
Member

VietND96 commented Dec 4, 2023

Yes, but may I know is this failure happened on parallel test executions or it's a single test failed immediately?

@cr-liorholtzman
Copy link
Author

@VietND96 Hi, I can confirm it happens only when running tests in parallel. single tests do not fail.
btw, I also tested it in chart 0.24 and its respective image and same issue happens.

@diemol
Copy link
Member

diemol commented Dec 4, 2023

If it only happens in parallel, it is primarily an issue with how you do parallelization, and you are probably reusing the WebDriver variable. If you need help figuring out that part, use the links below to ask questions or join the Selenium Slack community.

Copy link

github-actions bot commented Dec 4, 2023

💬 Please ask questions at:

@github-actions github-actions bot closed this as completed Dec 4, 2023
@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Dec 4, 2023

@diemol but it only happens after I upgrade from 4.10 to 4.15, it works perfectly well in 4.10.
More over our code and tests worked perfectly well thus far since Selenium3 so I really don't think it's our way of working.

@diemol
Copy link
Member

diemol commented Dec 4, 2023

Then please share a code snippet we can use to reproduce the issue. In theory it should be reproducible against any Grid. When that is available, I'd be happy to reopen the issue.

@VietND96
Copy link
Member

VietND96 commented Dec 5, 2023

Hi @cr-liorholtzman, you mentioned that the upgrade from 4.10. I am not sure you deployed 4.10 by using which chart version.
However, as I know, from chart version 0.19.0, there is a feat #1854 to update default autoscaling using ScaledJob. I saw in your YAML enabled enableWithExistingKEDA: true
Let me give some background on this change, and you can recheck the strategy to manage or cache web driver sessions in your test.

  • By default autoscaling.scalingType: job and combine with condition (autoscaling.enabled: true OR autoscaling.enableWithExistingKEDA: true). The ENV var SE_DRAIN_AFTER_SESSION_COUNT: 1 is set. This ENV is set via ConfigMap selenium-node-config and is referred in envFrom of node, so via kubectl describe pod you will don't see this ENV.
  • With that config, it means a node (running in a pod) will pick up only 1 session and it will be drained after that (when from client call driver.quit()). When a new request comes to the queue, a new pod will be up and serve a new run. It means number of sessions created equals to number of pods scaled, and sessionId will be closed whenever driver.quit() is called

@cr-liorholtzman
Copy link
Author

@VietND96 tnx for that info. I did deploy with 0.19 chart.
So should I try to increase SE_DRAIN_AFTER_SESSION_COUNT ?

@VietND96
Copy link
Member

VietND96 commented Dec 5, 2023

@cr-liorholtzman I think let's try to set it to 0...it means Node will never drain against the session count to see how test behaves

DRAIN_AFTER_SESSION_COUNT: '{{- and (eq (include "seleniumGrid.useKEDA" .) "true") (eq .Values.autoscaling.scalingType "job") | ternary "1" "0" -}}'

I think you can override that via each node extraEnvironmentVariables. For example:

chromeNode:
  extraEnvironmentVariables:
    - name: DRAIN_AFTER_SESSION_COUNT
      value: "0"

@cr-liorholtzman
Copy link
Author

@VietND96 Just to understand, so when will the pod get drained?

@cr-liorholtzman
Copy link
Author

@VietND96 btw it didn't help tested it now :/

@diemol
Copy link
Member

diemol commented Dec 5, 2023

@cr-liorholtzman where can I see the code snippet to reproduce the issue? You should also share the Grid logs, not the client logs.

@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Dec 5, 2023

@diemol regarding the code I'm still working on it can share the entire project so trying to build something that can be shared and will reproduce the issue. Regarding the logs, I did :) these are the router logs I shared:

18:15:18.613 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to execute request for an existing session: null
18:15:18.613 WARN [SeleniumSpanExporter$1.lambda$export$1] - java.lang.NullPointerException

18:15:18.614 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "d4d17e63ff7098658e7649136a93a0fe","eventTime": 1701281718613089014,"eventName": "exception","attributes": {"exception.message": "Unable to execute request for an existing session: null","exception.stacktrace": "java.lang.NullPointerException\n","exception.type": "java.lang.NullPointerException","http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.router.HandleSession","http.host": "selenium-dev-keda.eng.cybereason.net","http.method": "POST","http.request_content_length": "142","http.scheme": "HTTP","http.target": "\u002fsession\u002f0217c9741ddf4eb55223dbdf0c9bf872\u002fcookie","http.user_agent": "selenium\u002f4.10.0 (java unix)","session.id": "0217c9741ddf4eb55223dbdf0c9bf872"}}

18:16:18.599 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to execute request for an existing session: null
18:16:18.600 WARN [SeleniumSpanExporter$1.lambda$export$1] - java.lang.NullPointerException

18:16:18.600 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "64d5ae1f729481a859f8132c4d7d5c04","eventTime": 1701281778599005182,"eventName": "exception","attributes": {"exception.message": "Unable to execute request for an existing session: null","exception.stacktrace": "java.lang.NullPointerException\n","exception.type": "java.lang.NullPointerException","http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.router.HandleSession","http.host": "selenium-dev-keda.eng.cybereason.net","http.method": "GET","http.scheme": "HTTP","http.target": "\u002fsession\u002f0217c9741ddf4eb55223dbdf0c9bf872\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)","session.id": "0217c9741ddf4eb55223dbdf0c9bf872"}}

21:50:44.421 WARN [ProxyWebsocketsIntoGrid$ForwardingListener.onError] - Error proxying websocket command
java.io.IOException: Connection reset by peer
	at java.base/sun.nio.ch.FileDispatcherImpl.read0(Native Method)
	at java.base/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
	at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276)
	at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:245)
	at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:223)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:356)
	at java.net.http/jdk.internal.net.http.SocketTube.readAvailable(SocketTube.java:1153)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:821)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:175)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:271)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:224)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:763)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:941)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:245)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:957)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:912)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:912)

@diemol
Copy link
Member

diemol commented Dec 5, 2023

That is not helpful because it only shows the error, not what happens before the error which is more helpful. We also need to see the Distributor and Node logs.

@cr-liorholtzman
Copy link
Author

cr-liorholtzman commented Dec 6, 2023

@hi @diemol , Here are the logs, I'm afraid that I don't see any relevant errors in the Distributor or Note logs

This is the error I get in the client
org.openqa.selenium.NoSuchSessionException: invalid session id Build info: version: '4.10.0', revision: 'c14d967899' System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.107+', java.version: '11.0.18' Driver info: org.openqa.selenium.remote.RemoteWebDriver$ByteBuddy$rRnHE1SI$ByteBuddy$36PqjHMN Command: [9a52eff4dea821b371c743ed366e7ba3, getTitle {}] Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:39219}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.Valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.219:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.Valida...} Session ID: 9a52eff4dea821b371c743ed366e7ba3 at jdk.internal.reflect.GeneratedConstructorAccessor72.newInstance(Unknown Source) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490) at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.createException(W3CHttpResponseCodec.java:199) at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:132) at org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:51) at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:191) at org.openqa.selenium.remote.TracedCommandExecutor.execute(TracedCommandExecutor.java:51) at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:531) at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:590) at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:594) at org.openqa.selenium.remote.RemoteWebDriver.getTitle(RemoteWebDriver.java:300) at com.XXXX.ui.automation.infra.utils.DriverUtils.takePageScreenshot(DriverUtils.java:58) at com.XXXX.ui.automation.infra.DriverEventsListener.afterAnyWebDriverCall(DriverEventsListener.java:31) at org.openqa.selenium.support.events.EventFiringDecorator.fireAfterEvents(EventFiringDecorator.java:272) at org.openqa.selenium.support.events.EventFiringDecorator.lambda$afterCall$1(EventFiringDecorator.java:188) at java.base/java.util.Arrays$ArrayList.forEach(Arrays.java:4390) at org.openqa.selenium.support.events.EventFiringDecorator.afterCall(EventFiringDecorator.java:188) at org.openqa.selenium.support.decorators.DefaultDecorated.afterCall(DefaultDecorated.java:53) at org.openqa.selenium.support.decorators.WebDriverDecorator.lambda$createProxy$2(WebDriverDecorator.java:322) at net.bytebuddy.renamed.java.lang.Object$ByteBuddy$GCvYieuU.get(Unknown Source) at com.XXXX.ui.automation.infra.ActionBot.goToUrl(ActionBot.java:342)

On the Distributor side I see the session created but nothing else more relevant to it

`08:38:59.844 INFO [GridModel.setAvailability] - Switching Node d35bda54-c5eb-46e7-8123-8f3c43496cfd (uri: http://10.10.52.219:5555) from UP to DRAINING
08:38:59.866 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: a5d1d87b57f4b0ec74c780664282dfd6 
 Caps: Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:36781}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: {}, se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.Valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.219:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.Valida...}
08:39:00.055 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 9a52eff4dea821b371c743ed366e7ba3 
 Caps: Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:39219}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: {}, se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.Valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.219:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.Valida...}
08:39:30.748 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.749 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.750 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.750 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.750 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970747072430,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.750 WARN [SeleniumSpanExporter$1.lambda$export$1] - Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2
08:39:30.750 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970749505330,"eventName": "exception","attributes": {"exception.message": "Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2","logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.763 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.764 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.765 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.765 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970763146970,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.765 WARN [SeleniumSpanExporter$1.lambda$export$1] - Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2
08:39:30.765 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970765046650,"eventName": "exception","attributes": {"exception.message": "Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2","logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.777 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.779 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.779 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.779 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970777087460,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.779 WARN [SeleniumSpanExporter$1.lambda$export$1] - Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2
08:39:30.779 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970779092440,"eventName": "exception","attributes": {"exception.message": "Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2","logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.792 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.794 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.795 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.795 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970792073590,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.795 WARN [SeleniumSpanExporter$1.lambda$export$1] - Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2
08:39:30.795 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970794183020,"eventName": "exception","attributes": {"exception.message": "Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2","logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.807 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.809 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.810 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.810 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970807090580,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.810 WARN [SeleniumSpanExporter$1.lambda$export$1] - Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2
08:39:30.810 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970809339559,"eventName": "exception","attributes": {"exception.message": "Will retry session fd013c5e-2904-4f6f-bca0-a25866ddfbc2","logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}

08:39:30.823 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 76128f72-091c-41af-85d9-ac9209820fad, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 77adac4e-1e99-4f04-958b-b74fd27df2a2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 4aa96228-a0e3-4231-9b37-1f656d8ce0d6, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node 553cffb7-9b67-4ce5-84e6-a999169b00d2, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.824 WARN [GridModel.reserve] - Asked to reserve a slot on node d35bda54-c5eb-46e7-8123-8f3c43496cfd, but node is DRAINING
08:39:30.824 INFO [LocalDistributor.newSession] - Unable to find a free slot for request fd013c5e-2904-4f6f-bca0-a25866ddfbc2. 
 Capabilities {at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...} 
08:39:30.825 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a55128807d4c4afd99251430381a3acb","eventTime": 1701851970823099420,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {at:PagePerfResultsFilePath: \u002fhome\u002fjenkins\u002fagent\u002fworkspa..., at:screenshotLocation: \u002froot\u002fselenium\u002fshare\u002fdata\u002fs..., browserName: chrome, goog:chromeOptions: {args: [--remote-allow-origins=*, --ignore-ssl-errors=yes, --ignore-certificate-errors, --start-maximized], extensions: []}, se:name: SuspiciousEventsTest.valida..., zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.valida...}]"}}`

In the node logs again I see the session creation but nothing more:

`08:38:56.971 INFO [NodeServer.lambda$createHandlers$2] - Node has been added
08:38:59.841 INFO [LocalNode.checkSessionCount] - Draining Node, configured sessions value (1) has been reached.
08:38:59.847 INFO [LocalNode.newSession] - Session created by the Node. Id: a5d1d87b57f4b0ec74c780664282dfd6, Caps: Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:36781}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.Valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.219:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.Valida...}
08:39:00.041 INFO [LocalNode.checkSessionCount] - Draining Node, configured sessions value (1) has been reached.
08:39:00.044 INFO [LocalNode.newSession] - Session created by the Node. Id: 9a52eff4dea821b371c743ed366e7ba3, Caps: Capabilities {acceptInsecureCerts: false, at:PagePerfResultsFilePath: /home/jenkins/agent/workspa..., at:screenshotLocation: /root/selenium/share/data/s..., browserName: chrome, browserVersion: 119.0.6045.199, chrome: {chromedriverVersion: 119.0.6045.105 (38c72552c5e..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:39219}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: wss://selenium-test-keda.en..., se:cdpVersion: 119.0.6045.199, se:name: SuspiciousEventsTest.Valida..., se:vnc: wss://selenium-test-keda.en..., se:vncEnabled: true, se:vncLocalAddress: ws://10.10.52.219:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, zal:idleTimeout: 120, zal:name: SuspiciousEventsTest.Valida...}
08:39:00.141 INFO [ProxyNodeWebsockets.createWsEndPoint] - Establishing connection to ws://localhost:39219/devtools/browser/d52a7ac8-edaa-4643-a776-15f8fe451cbc
08:39:30.539 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "f1371eeb8fccb1c14243b0a79849f272","eventTime": 1701851970536385750,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "POST","http.request_content_length": "3","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002frefresh","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.562 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "23a0369141bfe5df4c4c8a0f705d2f6e","eventTime": 1701851970561476810,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "GET","http.request_content_length": "0","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.579 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "e4f6ac9dcec9734842038e65d32dc6cd","eventTime": 1701851970578102859,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "GET","http.request_content_length": "0","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002furl","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.594 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "44af0ed7bc507811b44f70458abb4adb","eventTime": 1701851970593140830,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "GET","http.request_content_length": "0","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.656 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "a3001fd6e14ad04877f587a9e035ad6a","eventTime": 1701851970655593470,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "GET","http.request_content_length": "0","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.685 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "5da96a3fea032ca2bb64c60f16f449cb","eventTime": 1701851970683779370,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "GET","http.request_content_length": "0","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002ftitle","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}

08:39:30.709 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "61c8d59717ba7975516d704386628123","eventTime": 1701851970708006909,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "10.10.52.219:5555","http.method": "POST","http.request_content_length": "142","http.scheme": "HTTP","http.status_code": 404,"http.target": "\u002fsession\u002f9a52eff4dea821b371c743ed366e7ba3\u002fcookie","http.user_agent": "selenium\u002f4.10.0 (java unix)"}}
`

Strangely, I now can't see any errors in the router logs, just the start of the pod.

@diemol
Copy link
Member

diemol commented Dec 7, 2023

When can you share the test code?

Copy link

github-actions bot commented Jan 7, 2024

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked and limited conversation to collaborators Jan 7, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants