Thread Info
  • State Verified Answer
  • Locked Locked
  • Replies 4 replies
  • Subscribers 1 subscriber
  • Views 1901 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

urid crash after 9.705-7 update

Jeff x

Aafter taking the 9.705-7 Up2Date around 10:38 AM EST, this morning, I received an email alert (around 2:55 PM today ) with the subject of:

[INFO-188] urid not running - restarted

The Web Filtering log has 86 of these entries:

2021:05:25-01:02:37 gateway URID[5038]: T=5038 ------ 2   - Warning: EARLY TIMEOUT: dns context 9 has 5978 ms before it should time out\n

Below is an excerpt from the same log file just before that email was sent:

2021:05:25-14:54:02 gateway httpproxy[5474]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="CONNECT" srcip="192.168.0.70" dstip="23.1.99.90" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="17008" request="0xdad81100" url="https://hostupdate.vmware.com/" referer="" error="" authtime="0" dnstime="69349" aptptime="87" cattime="16312" avscantime="0" fullreqtime="301104921" device="0" auth="0" ua="" exceptions="" category="175" reputation="trusted" categoryname="Software/Hardware" country="United States"
2021:05:25-14:54:06 gateway httpproxy[5474]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0xdb72b100" function="urid_categorize_url" file="uri_scanner.c" line="242" message="urid_query failed: (-4) "
2021:05:25-14:54:06 gateway httpproxy[5474]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0x91f4000" function="urid_categorize_url" file="uri_scanner.c" line="242" message="urid_query failed: (-4) "
2021:05:25-14:54:06 gateway httpproxy[5474]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0xdc3a3c00" function="urid_categorize_url" file="uri_scanner.c" line="242" message="urid_query failed: (-4) "
2021:05:25-14:54:06 gateway httpproxy[5474]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="GET" srcip="192.168.0.18" dstip="151.139.128.14" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="0" request="0xdc3a3c00" url="http://ocsp.sectigo.com/MFYwVKADAgEAME0wSzBJMAkGBSsOAwIaBQAEFEML0g5PE3oabJGPJOXafjJNRzPIBBSNjF7EVK2K4Xfpm%2FmbBeG4AY1h4QIQas3IyZWFrw04BGnZ9yjBxw%3D%3D" referer="" error="" authtime="0" dnstime="27485" aptptime="1404" cattime="3354578" avscantime="950" fullreqtime="3420702" device="0" auth="0" ua="com.apple.trustd/2.0" exceptions="" category="9999" reputation="neutral" categoryname="Categorization failed" country="United States" content-type="application/ocsp-response" application="ocsp" app-id="835" sandbox="-"
2021:05:25-14:54:07 gateway httpproxy[5474]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0x91f5500" function="urid_categorize_url" file="uri_scanner.c" line="242" message="urid_query failed: (-2) "
2021:05:25-14:54:07 gateway httpproxy[5474]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="GET" srcip="192.168.0.18" dstip="23.217.129.91" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="503" request="0x91f5500" url="http://r3.o.lencr.org/MFgwVqADAgEAME8wTTBLMAkGBSsOAwIaBQAEFEjayaD7K9MtT%2FDeaNL1Z7c1%2BbPEBBQULrMXt1hWy65QCUDmH6%2BdixTCxgISBCw9%2FhwsQ1SQrQi%2FO8VMkoZK" referer="" error="" authtime="0" dnstime="39083" aptptime="2176" cattime="2907" avscantime="1336" fullreqtime="77818" device="0" auth="0" ua="com.apple.trustd/2.0" exceptions="" category="9999" reputation="neutral" categoryname="Categorization failed" country="United States" content-type="application/ocsp-response" application="ocsp" app-id="835" sandbox="-"

I get an output of 10 when I run the following command:

wc -l /var/storage/chroot-http/etc/swa/urid.conf

Under the /var/storage/cores directory, I have these files:

confd.plx.6175
confd.plx.14560
ctasd.bin.4966
urid.5030

Self Monitoring Log:

2021:05:25-10:30:24 gateway selfmonng[3979]: I check Failed increment dbus_running counter 1 - 3
2021:05:25-10:30:29 gateway selfmonng[3979]: I check Failed increment dbus_running counter 2 - 3
2021:05:25-10:31:38 gateway selfmonng[3976]: T Selfmonitor Daemon successfully started
2021:05:25-10:31:38 gateway selfmonng[3976]: T Loading Selfmonitoring Checks complete  new=93 failed=0 retained=0 dropped=0
2021:05:25-10:31:58 gateway selfmonng[3976]: I check Failed increment named_running counter 1 - 3
2021:05:25-10:31:58 gateway selfmonng[3976]: I check Failed increment dnsresolver_running counter 1 - 3
2021:05:25-10:32:08 gateway selfmonng[3976]: T read config file '/etc/selfmonng.conf'
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment syslogng_running counter 1 - 3<30>May 25 10:32:38 selfmonng[3976]: I check Failed increment urid_running counter 1 - 3
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment cssd_running counter 1 - 3
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment afc_running counter 1 - 3
2021:05:25-14:54:09 gateway selfmonng[3976]: I check Failed increment urid_running counter 1 - 3
2021:05:25-14:54:14 gateway selfmonng[3976]: I check Failed increment urid_running counter 2 - 3
2021:05:25-14:54:19 gateway selfmonng[3976]: W check Failed increment urid_running counter 3 - 3
2021:05:25-14:54:19 gateway selfmonng[3976]: [INFO-188] urid not running - restarted
2021:05:25-14:54:19 gateway selfmonng[3976]: W NOTIFYEVENT Name=urid_running Level=INFO Id=188 sent
2021:05:25-14:54:19 gateway selfmonng[3976]: W triggerAction: 'cmd'
2021:05:25-14:54:19 gateway selfmonng[3976]: W actionCmd(+):  '/var/mdw/scripts/urid restart'
2021:05:25-14:54:20 gateway selfmonng[3976]: W child returned status: exit='0' signal='0'

More than 1000 of these in the Kernel Messages log:

2021:05:25-00:06:15 gateway kernel: [1818916.252473] end_request: I/O error, dev sda, sector 187963284

The following command returns 1:

cc get http use_sxl_urid

I don't know what this info indicates. I posted this info based on what others posted in a couple of old threads. I'm guessing I have a corrupted or bad hard drive and I should test the drive and re-image if the drive seems to be OK???

I'd be grateful for any advise.



This thread was automatically locked due to age.
Parents
  • FormerMember
    0 FormerMember

    Hi ,

    Thank you for reaching out to Sophos Community.

    Request to share output of below commands:

    utm:/root # gdb /var/storage/chroot-http/opt/ws/bin/urid /var/storage/cores/urid.5030

    utm:/root # dmesg

    utm:/root # zcat /var/log/selfmon/2021/05/selfmon-2021-05-25.log.gz | grep -i "urid"

    utm:/root # /var/storage/chroot-http/opt/ws/bin/uridquery www.sophos.com

    utm:/root # /var/mdw/scripts/urid status

Reply
  • FormerMember
    0 FormerMember

    Hi ,

    Thank you for reaching out to Sophos Community.

    Request to share output of below commands:

    utm:/root # gdb /var/storage/chroot-http/opt/ws/bin/urid /var/storage/cores/urid.5030

    utm:/root # dmesg

    utm:/root # zcat /var/log/selfmon/2021/05/selfmon-2021-05-25.log.gz | grep -i "urid"

    utm:/root # /var/storage/chroot-http/opt/ws/bin/uridquery www.sophos.com

    utm:/root # /var/mdw/scripts/urid status

Children
  • 0 in reply to FormerMember

    gdb /var/storage/chroot-http/opt/ws/bin/urid /var/storage/cores/urid.5030

    warning: core file may not match specified executable file.
[New LWP 5030]
Missing separate debuginfo for /lib/libz.so.1
Try: zypper install -C "debuginfo(build-id)=17c682a2bb9dc30d4c9c04687d990896b58c1e1c"
Missing separate debuginfo for /lib/libm.so.6
Try: zypper install -C "debuginfo(build-id)=faa7fb1594656a86189e0cc00c9c21368964d2de"
Missing separate debuginfo for /lib/librt.so.1
Try: zypper install -C "debuginfo(build-id)=31cf0be8804267fb5c2863864b11f4b11b517c0e"
Missing separate debuginfo for /lib/libcrypt.so.1
Try: zypper install -C "debuginfo(build-id)=1b43f8402ea164c5679077281bf6d86f5d02ba7b"
Missing separate debuginfo for /lib/libdl.so.2
Try: zypper install -C "debuginfo(build-id)=711a4048edac42866e43a854855dccc2ed21a0e1"
Missing separate debuginfo for /lib/libexpat.so.1
Try: zypper install -C "debuginfo(build-id)=73705c21f00808cc65001fc5588d92897fcf1bde"
Missing separate debuginfo for /usr/lib/libapr-1.so.0
Try: zypper install -C "debuginfo(build-id)=0afb766ab4b416ae619cf58dc30c584efb5dc32d"
Missing separate debuginfo for /usr/lib/libaprutil-1.so.0
Try: zypper install -C "debuginfo(build-id)=8ab5b8bd348c0fb60f2a66bc7d813f15acd3e69e"
Missing separate debuginfo for /lib/libc.so.6
Try: zypper install -C "debuginfo(build-id)=2304831afbb83789359603f1907f468f3b875f52"
Missing separate debuginfo for /lib/ld-linux.so.2
Try: zypper install -C "debuginfo(build-id)=ff7b2f4f56d6bc5666d05e5fc6a29e8655507d40"
Missing separate debuginfo for /lib/libpthread.so.0
Try: zypper install -C "debuginfo(build-id)=cefb5cb102b2401561c213955aa8627226ba83ce"
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `/var/chroot-http/opt/ws/bin/urid --chroot /var/chroot-http --user 810 --admin /'.
Program terminated with signal SIGBUS, Bus error.
#0  0x0805e895 in ?? ()
(gdb)

    dmesg

    I keep getting an error from the Sophos website when I paste the output.

    Below is a link to the output:
    https://pastebin.com/6k27NUuA

    zcat /var/log/selfmon/2021/05/selfmon-2021-05-25.log.gz | grep -i "urid"

    No such file or directory. Today is 5/25 so that file does not exist yet. Below is the content of today's log:

    2021:05:25-10:30:24 gateway selfmonng[3979]: I check Failed increment dbus_running counter 1 - 3
2021:05:25-10:30:29 gateway selfmonng[3979]: I check Failed increment dbus_running counter 2 - 3
2021:05:25-10:31:38 gateway selfmonng[3976]: T Selfmonitor Daemon successfully started
2021:05:25-10:31:38 gateway selfmonng[3976]: T Loading Selfmonitoring Checks complete  new=93 failed=0 retained=0 dropped=0
2021:05:25-10:31:58 gateway selfmonng[3976]: I check Failed increment named_running counter 1 - 3
2021:05:25-10:31:58 gateway selfmonng[3976]: I check Failed increment dnsresolver_running counter 1 - 3
2021:05:25-10:32:08 gateway selfmonng[3976]: T read config file '/etc/selfmonng.conf'
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment syslogng_running counter 1 - 3<30>May 25 10:32:38 selfmonng[3976]: I check Failed increment urid_running counter 1 - 3
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment cssd_running counter 1 - 3
2021:05:25-10:32:38 gateway selfmonng[3976]: I check Failed increment afc_running counter 1 - 3
2021:05:25-14:54:09 gateway selfmonng[3976]: I check Failed increment urid_running counter 1 - 3
2021:05:25-14:54:14 gateway selfmonng[3976]: I check Failed increment urid_running counter 2 - 3
2021:05:25-14:54:19 gateway selfmonng[3976]: W check Failed increment urid_running counter 3 - 3
2021:05:25-14:54:19 gateway selfmonng[3976]: [INFO-188] urid not running - restarted
2021:05:25-14:54:19 gateway selfmonng[3976]: W NOTIFYEVENT Name=urid_running Level=INFO Id=188 sent
2021:05:25-14:54:19 gateway selfmonng[3976]: W triggerAction: 'cmd'
2021:05:25-14:54:19 gateway selfmonng[3976]: W actionCmd(+):  '/var/mdw/scripts/urid restart'
2021:05:25-14:54:20 gateway selfmonng[3976]: W child returned status: exit='0' signal='0'
2021:05:25-22:09:54 gateway selfmonng[3976]: I check Failed increment afc_running counter 1 - 3

    /var/storage/chroot-http/opt/ws/bin/uridquery www.sophos.com

    Using URL: 'http://www.sophos.com'
Warning: tld list file /persist/perl-data/etc/data/urilist/current/sophos.tldlist not exist.
Sending:
    hostname = www.sophos.com
       host_part =
       domain_part =
       ip = 184.27.75.95
    port = (null)
    method = (null)
    scheme = http
    path = (null)
    query = (null)
Received:
    cat_id = 0x2100000069
    sxl_cat_id = 0x2100000069
    source_cat_id = 0x2100000069
    long_poll_id = 0x0
    scope = 0x7 (host,domain,page,)
    page_len = -1
    list_id = 2 (Sophos Labs)
    list_version =
    rule_id = 0
    threat =
    admin_tag_id = 0x0000000000

    /var/mdw/scripts/urid status

    :: Status urid

    --------------------------------------------------------------------
    Sophos UTM 9.719-3 - Home User
    Virtual machine on Dell Optiplex 3070
    i3-9100 @ 3.60 GHz, 16 GB RAM
    --------------------------------------------------------------------

  • FormerMember
    0 FormerMember in reply to Jeff x

    Hi ,

    There are few DRDY and I/O errors in dmesg.

    [34555.458832] ata1: EH complete
    [34615.388853] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
    [34615.388857] ata1.00: irq_stat 0x40000001
    [34615.388860] ata1.00: failed command: READ DMA
    [34615.388866] ata1.00: cmd c8/00:08:92:17:34/00:00:00:00:00/eb tag 11 dma 4096 in
    [34615.388866] res 51/40:00:94:17:34/00:00:0b:00:00/0b Emask 0x9 (media error)
    [34615.388869] ata1.00: status: { DRDY ERR }
    [34615.388872] ata1.00: error: { UNC }
    [34615.466200] ata1.00: configured for UDMA/133

    [34615.466241] sd 0:0:0:0: [sda] CDB:
    [34615.466243] cdb[0]=0x28: 28 00 0b 34 17 92 00 00 08 00
    [34615.466250] end_request: I/O error, dev sda, sector 187963284
    [34615.466265] ata1: EH complete
    [34675.403900] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
    [34675.403904] ata1.00: irq_stat 0x40000001
    [34675.403907] ata1.00: failed command: READ DMA
    [34675.403913] ata1.00: cmd c8/00:08:92:17:34/00:00:00:00:00/eb tag 2 dma 4096 in
    [34675.403913] res 51/40:00:94:17:34/00:00:0b:00:00/0b Emask 0x9 (media error)
    [34675.403916] ata1.00: status: { DRDY ERR }
    [34675.403918] ata1.00: error: { UNC }
    [34675.480636] ata1.00: configured for UDMA/133

    As it's a software appliance, I'd suggest reimaging it once and check if it works fine or not.

    Ensure to take the latest configuration backup before reimaging it.

  • 0 in reply to FormerMember

    Thanks for looking into this issue. I pulled the HDD, connected it to a Windows PC (via USB adapter) and ran HD Sentinel. Below is a screen cap of the SMART data:

    Time for a new HDD.

    I guess it was a coincidence that this happened shortly after applying the 9.705-7 update or doing so pushed the HDD "over the edge".

    --------------------------------------------------------------------
    Sophos UTM 9.719-3 - Home User
    Virtual machine on Dell Optiplex 3070
    i3-9100 @ 3.60 GHz, 16 GB RAM
    --------------------------------------------------------------------

Unfiltered HTML