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

Trace log for update email notifications #354

Merged
merged 1 commit into from
Nov 14, 2024

Conversation

Martinski4GitHub
Copy link
Collaborator

Added code to have some trace log for the post-reboot update email notifications (debugging purposes).

Added code to have some trace log for the post-reboot update email notifications (debugging purposes).
@ExtremeFiretop
Copy link
Owner

Added code to have some trace log for the post-reboot update email notifications (debugging purposes).

Approved! Sorry for the delay, I was just having dinner when all these notifications came in.
Let me reply to yours; starting from newest PR to oldest. (closed)

@Martinski4GitHub
Copy link
Collaborator Author

Added code to have some trace log for the post-reboot update email notifications (debugging purposes).

Approved! Sorry for the delay, I was just having dinner when all these notifications came in. Let me reply to yours; starting from newest PR to oldest. (closed)

No worries. I will be called for dinner in about 10 minutes so be warned >:) LOL

@ExtremeFiretop ExtremeFiretop merged commit b3c86f3 into ExtremeFiretop:dev Nov 14, 2024
1 check passed
@ExtremeFiretop
Copy link
Owner

Of course; the one time I test with this script with the additional logging it all worked the first time.

I'll try again, maybe just a fluke?

@ExtremeFiretop
Copy link
Owner

ExtremeFiretop commented Nov 14, 2024

And the verdict is....

My theory was right!!!! :D o.O HOW?!?

Nov 14 01:32:30 dropbear[4890]: Running in background
Nov 14 01:32:30 custom_script: Running /jffs/scripts/services-start
Nov 14 01:32:30 dbg: =====================
Nov 14 01:32:30 dbg: command: cat /proc/meminfo
Nov 14 01:32:30 dbg: MemTotal:        2048044 kB
Nov 14 01:32:30 dbg: MemFree:         1297164 kB
Nov 14 01:32:30 dbg: MemAvailable:    1296572 kB
Nov 14 01:32:30 dbg: Buffers:           13276 kB
Nov 14 01:32:30 dbg: Cached:            40632 kB
Nov 14 01:32:30 dbg: SwapCached:            0 kB
Nov 14 01:32:30 dbg: Active:            67392 kB
Nov 14 01:32:30 dbg: Inactive:          20884 kB
Nov 14 01:32:30 dbg: Active(anon):      34772 kB
Nov 14 01:32:30 dbg: Inactive(anon):      896 kB
Nov 14 01:32:30 dbg: Active(file):      32620 kB
Nov 14 01:32:30 dbg: Inactive(file):    19988 kB
Nov 14 01:32:30 dbg: Unevictable:           0 kB
Nov 14 01:32:30 dbg: Mlocked:               0 kB
Nov 14 01:32:30 dbg: SwapTotal:             0 kB
Nov 14 01:32:30 dbg: SwapFree:              0 kB
Nov 14 01:32:30 dbg: Dirty:                12 kB
Nov 14 01:32:30 dbg: Writeback:             0 kB
Nov 14 01:32:30 dbg: AnonPages:         34448 kB
Nov 14 01:32:30 dbg: Mapped:            17004 kB
Nov 14 01:32:30 dbg: Shmem:              1300 kB
Nov 14 01:32:30 dbg: Slab:             149184 kB
Nov 14 01:32:30 dbg: SReclaimable:       6240 kB
Nov 14 01:32:30 dbg: SUnreclaim:       142944 kB
Nov 14 01:32:30 dbg: KernelStack:        2896 kB
Nov 14 01:32:30 dbg: PageTables:         2172 kB
Nov 14 01:32:30 dbg: NFS_Unstable:          0 kB
Nov 14 01:32:30 dbg: Bounce:                0 kB
Nov 14 01:32:30 dbg: WritebackTmp:          0 kB
Nov 14 01:32:30 dbg: CommitLimit:     2048044 kB
Nov 14 01:32:30 dbg: Committed_AS:      94168 kB
Nov 14 01:32:30 dbg: VmallocTotal:   263061440 kB
Nov 14 01:32:30 dbg: VmallocUsed:           0 kB
Nov 14 01:32:30 dbg: VmallocChunk:          0 kB
Nov 14 01:32:30 dbg: Percpu:              752 kB
Nov 14 01:32:30 dbg: CmaTotal:         483328 kB
Nov 14 01:32:30 dbg: CmaFree:           64232 kB
Nov 14 01:32:30 dbg: command: free
Nov 14 01:32:30 dbg:              total       used       free     shared    buffers     cached
Nov 14 01:32:30 dbg: Mem:       2048044     751148    1296896       1300      13308      40600
Nov 14 01:32:30 dbg: -/+ buffers/cache:     697240    1350804
Nov 14 01:32:30 dbg: Swap:            0          0          0
Nov 14 01:32:30 dbg: command: cat /proc/slabinfo
Nov 14 01:32:30 dbg: slabinfo - version: 2.1
Nov 14 01:32:30 dbg: # name            <active_objs> <num_objs> <objsize> <objperslab> <pagesperslab> : tunables <limit> <batchcount> <sharedfactor> : slabdata <active_slabs> <num_slabs> <sharedavail>
Nov 14 01:32:30 dbg: bcm_mcast_host_client_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_if_netdev_cache    512    512     32  128    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: bcm_mcast_rxinfo_node_cache      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_clientinfo_node_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_grpinfo_node_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_fc_flowkey_cache      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_fc_flowhdl_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_mld_exception_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_mld_rep_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_mld_grp_cache      0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_igmp_exception_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_igmp_rep_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcm_mcast_igmp_grp_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: cmdlist_buffer         0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcmVlan_blogRule_id      0      0     16  256    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcmVlan_flowPath       0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcmVlan_flowDev        0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bcmvlan_tableEntry     54     54    448   18    2 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: bcmvlan_realDev       75     75    648   25    4 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: bcmvlan_vlanDev      306    306     40  102    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: bpmbuf              7010   7016  11136    1    4 : tunables    0    0    0 : slabdata   7016   7016      0
Nov 14 01:32:30 dbg: ubi_wl_entry_slab   2048   2048     32  128    1 : tunables    0    0    0 : slabdata     16     16      0
Nov 14 01:32:30 dbg: ubifs_inode_slab     368    368    704   23    4 : tunables    0    0    0 : slabdata     16     16      0
Nov 14 01:32:30 dbg: SCTPv6                22     22   1472   22    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: SCTP                   0      0   1344   24    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: sctp_chunk             0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: sctp_bind_bucket       0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bridge_fdb_cache     128    128    128   32    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: nf-frags               0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: xfrm6_tunnel_spi       0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ip6-frags              0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: fib6_nodes           128    128     64   64    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: ip6_dst_cache         32     32    256   16    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: ip6_mrt_cache          0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: PINGv6                 0      0   1152   28    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: RAWv6                112    112   1152   28    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: UDPLITEv6              0      0   1216   26    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: UDPv6                 52     52   1216   26    8 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: tw_sock_TCPv6          0      0    224   18    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: request_sock_TCPv6      0      0    296   27    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: TCPv6                  0      0   2304   14    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: nf_conncount_rb        0      0     96   42    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: nf_conncount_tuple      0      0     72   56    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: nf_conntrack_expect      0      0    216   18    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: nf_conntrack         162    162    448   18    2 : tunables    0    0    0 : slabdata      9      9      0
Nov 14 01:32:30 dbg: sgpool-128             8      8   4096    8    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: sgpool-64             16     16   2048   16    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: sgpool-32             16     16   1024   16    4 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: sgpool-16             16     16    512   16    2 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: sgpool-8              16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: fuse_request           0      0    400   20    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: fuse_inode             0      0    768   21    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_inode_cache      0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_node_frag        0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_refblock         0      0    240   17    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_tmp_dnode        0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_raw_inode        0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_raw_dirent       0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_full_dnode       0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jffs2_i                0      0    664   24    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: squashfs_inode_cache    900    900    640   25    4 : tunables    0    0    0 : slabdata     36     36      0
Nov 14 01:32:30 dbg: jbd2_transaction_s      0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jbd2_inode             0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jbd2_journal_handle      0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jbd2_journal_head      0      0    120   34    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jbd2_revoke_table_s      0      0     16  256    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: jbd2_revoke_record_s      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_inode_cache       0      0   1016   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_free_data         0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_allocation_context      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_prealloc_space      0      0    104   39    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_system_zone       0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_io_end            0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ext4_extent_status      0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: mbcache                0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: dnotify_mark           0      0     80   51    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: dnotify_struct         0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: dio                    0      0    640   25    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: bio-1                 16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: fasync_cache           0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: posix_timers_cache      0      0    240   17    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: UNIX                 102    102    960   17    4 : tunables    0    0    0 : slabdata      6      6      0
Nov 14 01:32:30 dbg: ip4-frags              0      0    208   19    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ip_mrt_cache           0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: UDP-Lite               0      0   1024   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: tcp_bind_bucket      256    256     64   64    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: inet_peer_cache       42     42    192   21    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: secpath_cache          0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: xfrm_dst_cache         0      0    320   25    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: xfrm_state             0      0    768   21    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ip_fib_trie          340    340     48   85    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: ip_fib_alias         292    292     56   73    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: ip_dst_cache          84     84    192   21    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: PING                   0      0    896   18    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: RAW                   68     68    960   17    4 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: UDP                   80     80   1024   16    4 : tunables    0    0    0 : slabdata      5      5      0
Nov 14 01:32:30 dbg: tw_sock_TCP           36     36    224   18    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: request_sock_TCP      81     81    296   27    2 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: TCP                   60     60   2112   15    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: eventpoll_pwq        168    168     72   56    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: eventpoll_epi        128    128    128   32    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: inotify_inode_mark    153    153     80   51    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: blog_rule              0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: request_queue         15     15   2184   15    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: blkdev_requests        0      0    296   27    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: blkdev_ioc           156    156    104   39    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: bio-0                432    432    256   16    1 : tunables    0    0    0 : slabdata     27     27      0
Nov 14 01:32:30 dbg: biovec-max            24     24   4096    8    8 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: biovec-128             0      0   2048   16    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: biovec-64              0      0   1024   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: biovec-16              0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ksm_mm_slot            0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ksm_stable_node        0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: ksm_rmap_item          0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: uid_cache             21     21    192   21    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: sock_inode_cache     300    300    640   25    4 : tunables    0    0    0 : slabdata     12     12      0
Nov 14 01:32:30 dbg: skbuff_cb_store_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: skbuff_fclone_cache     78     78   1216   26    8 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: skbuff_head_cache   6496   6496    576   28    4 : tunables    0    0    0 : slabdata    232    232      0
Nov 14 01:32:30 dbg: configfs_dir_cache      0      0     96   42    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:32:30 dbg: file_lock_cache       80     80    200   20    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: file_lock_ctx        292    292     56   73    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: fsnotify_mark_connector    510    510     24  170    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: shmem_inode_cache    720    720    664   24    4 : tunables    0    0    0 : slabdata     30     30      0
Nov 14 01:32:30 dbg: proc_dir_entry       735    735    192   21    1 : tunables    0    0    0 : slabdata     35     35      0
Nov 14 01:32:30 dbg: pde_opener           408    408     40  102    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: proc_inode_cache    1000   1000    648   25    4 : tunables    0    0    0 : slabdata     40     40      0
Nov 14 01:32:30 dbg: seq_file             128    128    128   32    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: sigqueue             100    100    160   25    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: bdev_cache            38     38    832   19    4 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:32:30 dbg: kernfs_node_cache  21300  21300    136   30    1 : tunables    0    0    0 : slabdata    710    710      0
Nov 14 01:32:30 dbg: mnt_cache             84     84    384   21    2 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: filp                1810   1984    256   16    1 : tunables    0    0    0 : slabdata    124    124      0
Nov 14 01:32:30 dbg: inode_cache         2492   2492    576   28    4 : tunables    0    0    0 : slabdata     89     89      0
Nov 14 01:32:30 dbg: dentry              6237   6237    192   21    1 : tunables    0    0    0 : slabdata    297    297      0
Nov 14 01:32:30 dbg: names_cache           32     32   4096    8    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: key_jar               16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: buffer_head        13377  13377    104   39    1 : tunables    0    0    0 : slabdata    343    343      0
Nov 14 01:32:30 dbg: nsproxy               73     73     56   73    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:32:30 dbg: vm_area_struct      6380   6380    184   22    1 : tunables    0    0    0 : slabdata    290    290      0
Nov 14 01:32:30 dbg: mm_struct            126    126    896   18    4 : tunables    0    0    0 : slabdata      7      7      0
Nov 14 01:32:30 dbg: fs_cache             256    256     64   64    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:32:30 dbg: files_cache          115    115    704   23    4 : tunables    0    0    0 : slabdata      5      5      0
Nov 14 01:32:30 dbg: signal_cache         357    357    960   17    4 : tunables    0    0    0 : slabdata     21     21      0
Nov 14 01:32:30 dbg: sighand_cache        210    210   2112   15    8 : tunables    0    0    0 : slabdata     14     14      0
Nov 14 01:32:30 dbg: task_struct          239    264   2688   12    8 : tunables    0    0    0 : slabdata     22     22      0
Nov 14 01:32:30 dbg: cred_jar             756    756    192   21    1 : tunables    0    0    0 : slabdata     36     36      0
Nov 14 01:32:30 dbg: anon_vma_chain      5504   5504     64   64    1 : tunables    0    0    0 : slabdata     86     86      0
Nov 14 01:32:30 dbg: anon_vma            3198   3198    104   39    1 : tunables    0    0    0 : slabdata     82     82      0
Nov 14 01:32:30 dbg: pid                  384    384    128   32    1 : tunables    0    0    0 : slabdata     12     12      0
Nov 14 01:32:30 dbg: pool_workqueue        48     48    256   16    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:32:30 dbg: radix_tree_node     1064   1064    584   28    4 : tunables    0    0    0 : slabdata     38     38      0
Nov 14 01:32:30 dbg: kmalloc-8192         304    316   8192    4    8 : tunables    0    0    0 : slabdata     79     79      0
Nov 14 01:32:30 dbg: kmalloc-4096        1720   1720   4096    8    8 : tunables    0    0    0 : slabdata    215    215      0
Nov 14 01:32:30 dbg: kmalloc-2048         576    576   2048   16    8 : tunables    0    0    0 : slabdata     36     36      0
Nov 14 01:32:30 dbg: kmalloc-1024         898    928   1024   16    4 : tunables    0    0    0 : slabdata     58     58      0
Nov 14 01:32:30 dbg: kmalloc-512         1216   1216    512   16    2 : tunables    0    0    0 : slabdata     76     76      0
Nov 14 01:32:30 dbg: kmalloc-256         1872   1872    256   16    1 : tunables    0    0    0 : slabdata    117    117      0
Nov 14 01:32:30 dbg: kmalloc-128        37594  40704    128   32    1 : tunables    0    0    0 : slabdata   1272   1272      0
Nov 14 01:32:30 dbg: kmem_cache_node      192    192    128   32    1 : tunables    0    0    0 : slabdata      6      6      0
Nov 14 01:32:30 dbg: kmem_cache           192    192    256   16    1 : tunables    0    0    0 : slabdata     12     12      0
Nov 14 01:32:30 dbg: command: bpm status
Nov 14 01:32:30 kernel: ------------------ BPM Config : Dynamic ----------------
Nov 14 01:32:30 kernel: bpm_max_buf_count                = 28926
Nov 14 01:32:30 kernel: bpm_initial_buf_count            = 5785
Nov 14 01:32:30 kernel: bpm_buf_avail_lower_th           = 512
Nov 14 01:32:30 kernel: bpm_buf_expand_step_size         = 128
Nov 14 01:32:30 kernel: bpm_buf_shrink_step_size         = 32
Nov 14 01:32:30 kernel: bpm_buf_expn_pool_fast_shrink_th = 5785
Nov 14 01:32:30 kernel: bpm_max_skb_count                = 28926
Nov 14 01:32:30 kernel: bpm_initial_skb_count            = 5785
Nov 14 01:32:30 kernel: bpm_skb_avail_lower_th           = 512
Nov 14 01:32:30 kernel: bpm_skb_expand_step_size         = 128
Nov 14 01:32:30 kernel: bpm_skb_shrink_step_size         = 32
Nov 14 01:32:30 kernel: bpm_soak_timer_duration          = 10000
Nov 14 01:32:30 kernel: ----------------------- BPM Status --------------------------
Nov 14 01:32:30 kernel: base pool tot_buf       = 5785
Nov 14 01:32:30 kernel: cur                     = 5755
Nov 14 01:32:30 kernel: exp pool tot_buf        = 1223
Nov 14 01:32:30 kernel: exp pool cur            = 663
Nov 14 01:32:30 kernel: avail                   = 591
Nov 14 01:32:30 kernel: no_buf_err              = 0
Nov 14 01:32:30 kernel: cum_alloc               = 9728
Nov 14 01:32:30 kernel: cum_free                = 3311
Nov 14 01:32:30 kernel: exp cum_alloc           = 1278
Nov 14 01:32:30 kernel: exp cum_free            = 615
Nov 14 01:32:30 kernel: min_availability        = 0
Nov 14 01:32:30 kernel: max_inuse_watermark     = 6448
Nov 14 01:32:30 kernel: max_watermark           = 7040
Nov 14 01:32:30 kernel: buf_expansion_count     = 10
Nov 14 01:32:30 kernel: buf_shrink_count        = 1
Nov 14 01:32:30 kernel: buf_exp_fail_count      = 0
Nov 14 01:32:30 kernel: buf_inthr_alloc_count   = 231
Nov 14 01:32:30 kernel: skb_inthr_alloc_count   = 0
Nov 14 01:32:30 kernel: max_dyn                 = 28926
Nov 14 01:32:30 kernel: -------------------- BPM SKB Pool Status -----------------------
Nov 14 01:32:30 kernel: skb_avail                       = 5785
Nov 14 01:32:30 kernel: skb_total                       = 5785
Nov 14 01:32:30 kernel: skb_bound                       = 28926
Nov 14 01:32:30 kernel: min_skb_avail_cnt               = 5785
Nov 14 01:32:30 kernel: max_skb_wm                      = 5785
Nov 14 01:32:30 kernel: max_inuse_skb_wm                = 0
Nov 14 01:32:30 kernel: skb_alloc_cnt                   = 0
Nov 14 01:32:30 kernel: skb_bpm_alloc_cnt               = 0
Nov 14 01:32:30 kernel: skb_free_cnt                    = 0
Nov 14 01:32:30 kernel: skb_fast_free_cnt               = 0
Nov 14 01:32:30 kernel: skb_fail_cnt                    = 0
Nov 14 01:32:30 kernel: skb_grow_cnt                    = 0
Nov 14 01:32:30 kernel: -------------------------------------------------------------
Nov 14 01:32:30 dbg: ==================
Nov 14 01:32:30 kernel: link down LAN1
Nov 14 01:32:30 scMerlin: Waiting for NTP to sync...
Nov 14 01:32:30 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:32:30 YazDHCP: Trying again with directory [/opt/var/SavedUserIcons]
Nov 14 01:32:30 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:32:30 YazDHCP: Trying again with directory [/opt/var/SavedUserIcons]
Nov 14 01:32:30 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:32:30 YazDHCP: Trying again with directory [/jffs/configs/SavedUserIcons]
Nov 14 01:32:30 YazDHCP: *WARNING*: Temporary Backup directory [/jffs/configs/SavedUserIcons]
Nov 14 01:32:31 kernel: link up LAN1
Nov 14 01:32:31 pppd[5810]: Plugin rp-pppoe.so loaded.
Nov 14 01:32:31 pppd[5810]: RP-PPPoE plugin version 3.11 compiled against pppd 2.4.7
Nov 14 01:32:31 pppd[5839]: pppd 2.4.7 started by Admin, uid 0
Nov 14 01:32:31 rc_service: cfg_server 4844:notify_rc update_nbr
Nov 14 01:32:31 rc_service: waitting "restart_firewall" via  ...
Nov 14 01:32:31 [MerlinAU.sh] 5143: **ERROR**: The shell script 'MerlinAU.sh' is already running [Lock file: 0 secs.]
Nov 14 01:32:31 [MerlinAU.sh] 5143: Exiting...
Nov 14 01:32:31 kernel: SCSI subsystem initialized

@ExtremeFiretop
Copy link
Owner

Just tested again by downgrading to beta1:
SAME THING! LARGE EYES

Nov 14 01:47:37 custom_script: Running /jffs/scripts/services-start
Nov 14 01:47:37 dbg: =====================
Nov 14 01:47:37 dbg: command: cat /proc/meminfo
Nov 14 01:47:37 dbg: MemTotal:        2048044 kB
Nov 14 01:47:37 dbg: MemFree:         1296780 kB
Nov 14 01:47:37 dbg: MemAvailable:    1296144 kB
Nov 14 01:47:37 dbg: Buffers:           13280 kB
Nov 14 01:47:37 dbg: Cached:            40540 kB
Nov 14 01:47:37 dbg: SwapCached:            0 kB
Nov 14 01:47:37 dbg: Active:            67124 kB
Nov 14 01:47:37 dbg: Inactive:          21052 kB
Nov 14 01:47:37 dbg: Active(anon):      34712 kB
Nov 14 01:47:37 dbg: Inactive(anon):      896 kB
Nov 14 01:47:37 dbg: Active(file):      32412 kB
Nov 14 01:47:37 dbg: Inactive(file):    20156 kB
Nov 14 01:47:37 dbg: Unevictable:           0 kB
Nov 14 01:47:37 dbg: Mlocked:               0 kB
Nov 14 01:47:37 dbg: SwapTotal:             0 kB
Nov 14 01:47:37 dbg: SwapFree:              0 kB
Nov 14 01:47:37 dbg: Dirty:                 8 kB
Nov 14 01:47:37 dbg: Writeback:             0 kB
Nov 14 01:47:37 dbg: AnonPages:         34576 kB
Nov 14 01:47:37 dbg: Mapped:            17340 kB
Nov 14 01:47:37 dbg: Shmem:              1256 kB
Nov 14 01:47:37 dbg: Slab:             149340 kB
Nov 14 01:47:37 dbg: SReclaimable:       6232 kB
Nov 14 01:47:37 dbg: SUnreclaim:       143108 kB
Nov 14 01:47:37 dbg: KernelStack:        2928 kB
Nov 14 01:47:37 dbg: PageTables:         1940 kB
Nov 14 01:47:37 dbg: NFS_Unstable:          0 kB
Nov 14 01:47:37 dbg: Bounce:                0 kB
Nov 14 01:47:37 dbg: WritebackTmp:          0 kB
Nov 14 01:47:37 dbg: CommitLimit:     2048044 kB
Nov 14 01:47:37 dbg: Committed_AS:      94544 kB
Nov 14 01:47:37 dbg: VmallocTotal:   263061440 kB
Nov 14 01:47:37 dbg: VmallocUsed:           0 kB
Nov 14 01:47:37 dbg: VmallocChunk:          0 kB
Nov 14 01:47:37 dbg: Percpu:              752 kB
Nov 14 01:47:37 dbg: CmaTotal:         483328 kB
Nov 14 01:47:37 dbg: CmaFree:           64232 kB
Nov 14 01:47:37 dbg: command: free
Nov 14 01:47:37 dbg:              total       used       free     shared    buffers     cached
Nov 14 01:47:37 dbg: Mem:       2048044     751768    1296276       1256      13280      40724
Nov 14 01:47:37 dbg: -/+ buffers/cache:     697764    1350280
Nov 14 01:47:37 dbg: Swap:            0          0          0
Nov 14 01:47:37 dbg: command: cat /proc/slabinfo
Nov 14 01:47:37 dbg: slabinfo - version: 2.1
Nov 14 01:47:37 dbg: # name            <active_objs> <num_objs> <objsize> <objperslab> <pagesperslab> : tunables <limit> <batchcount> <sharedfactor> : slabdata <active_slabs> <num_slabs> <sharedavail>
Nov 14 01:47:37 dbg: bcm_mcast_host_client_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_if_netdev_cache    512    512     32  128    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: bcm_mcast_rxinfo_node_cache      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_clientinfo_node_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_grpinfo_node_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_fc_flowkey_cache      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_fc_flowhdl_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_mld_exception_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_mld_rep_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_mld_grp_cache      0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_igmp_exception_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_igmp_rep_cache      0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcm_mcast_igmp_grp_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: cmdlist_buffer         0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcmVlan_blogRule_id      0      0     16  256    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcmVlan_flowPath       0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcmVlan_flowDev        0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bcmvlan_tableEntry     36     36    448   18    2 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: bcmvlan_realDev       50     50    648   25    4 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: bcmvlan_vlanDev      306    306     40  102    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: bpmbuf              7010   7016  11136    1    4 : tunables    0    0    0 : slabdata   7016   7016      0
Nov 14 01:47:37 dbg: ubi_wl_entry_slab   2048   2048     32  128    1 : tunables    0    0    0 : slabdata     16     16      0
Nov 14 01:47:37 dbg: ubifs_inode_slab     345    345    704   23    4 : tunables    0    0    0 : slabdata     15     15      0
Nov 14 01:47:37 dbg: SCTPv6                22     22   1472   22    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: SCTP                   0      0   1344   24    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: sctp_chunk             0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: sctp_bind_bucket       0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bridge_fdb_cache     128    128    128   32    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: nf-frags               0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: xfrm6_tunnel_spi       0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ip6-frags              0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: fib6_nodes           128    128     64   64    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: ip6_dst_cache         16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: ip6_mrt_cache          0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: PINGv6                 0      0   1152   28    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: RAWv6                112    112   1152   28    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: UDPLITEv6              0      0   1216   26    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: UDPv6                 52     52   1216   26    8 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: tw_sock_TCPv6          0      0    224   18    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: request_sock_TCPv6      0      0    296   27    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: TCPv6                  0      0   2304   14    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: nf_conncount_rb        0      0     96   42    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: nf_conncount_tuple      0      0     72   56    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: nf_conntrack_expect      0      0    216   18    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: nf_conntrack         288    288    448   18    2 : tunables    0    0    0 : slabdata     16     16      0
Nov 14 01:47:37 dbg: sgpool-128             8      8   4096    8    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: sgpool-64             16     16   2048   16    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: sgpool-32             16     16   1024   16    4 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: sgpool-16             16     16    512   16    2 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: sgpool-8              16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: fuse_request           0      0    400   20    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: fuse_inode             0      0    768   21    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_inode_cache      0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_node_frag        0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_refblock         0      0    240   17    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_tmp_dnode        0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_raw_inode        0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_raw_dirent       0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_full_dnode       0      0     24  170    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jffs2_i                0      0    664   24    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: squashfs_inode_cache    900    900    640   25    4 : tunables    0    0    0 : slabdata     36     36      0
Nov 14 01:47:37 dbg: jbd2_transaction_s      0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jbd2_inode             0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jbd2_journal_handle      0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jbd2_journal_head      0      0    120   34    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jbd2_revoke_table_s      0      0     16  256    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: jbd2_revoke_record_s      0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_inode_cache       0      0   1016   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_free_data         0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_allocation_context      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_prealloc_space      0      0    104   39    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_system_zone       0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_io_end            0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ext4_extent_status      0      0     40  102    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: mbcache                0      0     56   73    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: dnotify_mark           0      0     80   51    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: dnotify_struct         0      0     32  128    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: dio                    0      0    640   25    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: bio-1                 16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: fasync_cache           0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: posix_timers_cache      0      0    240   17    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: UNIX                 102    102    960   17    4 : tunables    0    0    0 : slabdata      6      6      0
Nov 14 01:47:37 dbg: ip4-frags              0      0    208   19    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ip_mrt_cache           0      0    192   21    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: UDP-Lite               0      0   1024   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: tcp_bind_bucket      256    256     64   64    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: inet_peer_cache       42     42    192   21    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: secpath_cache          0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: xfrm_dst_cache         0      0    320   25    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: xfrm_state             0      0    768   21    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ip_fib_trie          340    340     48   85    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: ip_fib_alias         292    292     56   73    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: ip_dst_cache          84     84    192   21    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: PING                   0      0    896   18    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: RAW                   68     68    960   17    4 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: UDP                   64     64   1024   16    4 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: tw_sock_TCP           54     54    224   18    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: request_sock_TCP      81     81    296   27    2 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: TCP                   60     60   2112   15    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: eventpoll_pwq        168    168     72   56    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: eventpoll_epi         96     96    128   32    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: inotify_inode_mark    153    153     80   51    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: blog_rule              0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: request_queue         15     15   2184   15    8 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: blkdev_requests        0      0    296   27    2 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: blkdev_ioc           156    156    104   39    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: bio-0                416    416    256   16    1 : tunables    0    0    0 : slabdata     26     26      0
Nov 14 01:47:37 dbg: biovec-max            24     24   4096    8    8 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: biovec-128             0      0   2048   16    8 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: biovec-64              0      0   1024   16    4 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: biovec-16              0      0    256   16    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ksm_mm_slot            0      0     48   85    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ksm_stable_node        0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: ksm_rmap_item          0      0     64   64    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: uid_cache             21     21    192   21    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: sock_inode_cache     300    300    640   25    4 : tunables    0    0    0 : slabdata     12     12      0
Nov 14 01:47:37 dbg: skbuff_cb_store_cache      0      0    128   32    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: skbuff_fclone_cache     78     78   1216   26    8 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: skbuff_head_cache   6468   6468    576   28    4 : tunables    0    0    0 : slabdata    231    231      0
Nov 14 01:47:37 dbg: configfs_dir_cache      0      0     96   42    1 : tunables    0    0    0 : slabdata      0      0      0
Nov 14 01:47:37 dbg: file_lock_cache       80     80    200   20    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: file_lock_ctx        292    292     56   73    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: fsnotify_mark_connector    510    510     24  170    1 : tunables    0    0    0 : slabdata      3      3      0
Nov 14 01:47:37 dbg: shmem_inode_cache    744    744    664   24    4 : tunables    0    0    0 : slabdata     31     31      0
Nov 14 01:47:37 dbg: proc_dir_entry       735    735    192   21    1 : tunables    0    0    0 : slabdata     35     35      0
Nov 14 01:47:37 dbg: pde_opener           408    408     40  102    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: proc_inode_cache    1000   1000    648   25    4 : tunables    0    0    0 : slabdata     40     40      0
Nov 14 01:47:37 dbg: seq_file             128    128    128   32    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: sigqueue             100    100    160   25    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: bdev_cache            19     19    832   19    4 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: kernfs_node_cache  21090  21090    136   30    1 : tunables    0    0    0 : slabdata    703    703      0
Nov 14 01:47:37 dbg: mnt_cache             84     84    384   21    2 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: filp                2016   2016    256   16    1 : tunables    0    0    0 : slabdata    126    126      0
Nov 14 01:47:37 dbg: inode_cache         2492   2492    576   28    4 : tunables    0    0    0 : slabdata     89     89      0
Nov 14 01:47:37 dbg: dentry              6363   6363    192   21    1 : tunables    0    0    0 : slabdata    303    303      0
Nov 14 01:47:37 dbg: names_cache           32     32   4096    8    8 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: key_jar               16     16    256   16    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: buffer_head        13377  13377    104   39    1 : tunables    0    0    0 : slabdata    343    343      0
Nov 14 01:47:37 dbg: nsproxy               73     73     56   73    1 : tunables    0    0    0 : slabdata      1      1      0
Nov 14 01:47:37 dbg: vm_area_struct      6666   6666    184   22    1 : tunables    0    0    0 : slabdata    303    303      0
Nov 14 01:47:37 dbg: mm_struct            108    108    896   18    4 : tunables    0    0    0 : slabdata      6      6      0
Nov 14 01:47:37 dbg: fs_cache             256    256     64   64    1 : tunables    0    0    0 : slabdata      4      4      0
Nov 14 01:47:37 dbg: files_cache          115    115    704   23    4 : tunables    0    0    0 : slabdata      5      5      0
Nov 14 01:47:37 dbg: signal_cache         425    425    960   17    4 : tunables    0    0    0 : slabdata     25     25      0
Nov 14 01:47:37 dbg: sighand_cache        195    195   2112   15    8 : tunables    0    0    0 : slabdata     13     13      0
Nov 14 01:47:37 dbg: task_struct          274    300   2688   12    8 : tunables    0    0    0 : slabdata     25     25      0
Nov 14 01:47:37 dbg: cred_jar             756    756    192   21    1 : tunables    0    0    0 : slabdata     36     36      0
Nov 14 01:47:37 dbg: anon_vma_chain      6464   6464     64   64    1 : tunables    0    0    0 : slabdata    101    101      0
Nov 14 01:47:37 dbg: anon_vma            3042   3042    104   39    1 : tunables    0    0    0 : slabdata     78     78      0
Nov 14 01:47:37 dbg: pid                  416    416    128   32    1 : tunables    0    0    0 : slabdata     13     13      0
Nov 14 01:47:37 dbg: pool_workqueue        32     32    256   16    1 : tunables    0    0    0 : slabdata      2      2      0
Nov 14 01:47:37 dbg: radix_tree_node     1036   1036    584   28    4 : tunables    0    0    0 : slabdata     37     37      0
Nov 14 01:47:37 dbg: kmalloc-8192         307    316   8192    4    8 : tunables    0    0    0 : slabdata     79     79      0
Nov 14 01:47:37 dbg: kmalloc-4096        1704   1704   4096    8    8 : tunables    0    0    0 : slabdata    213    213      0
Nov 14 01:47:37 dbg: kmalloc-2048         608    608   2048   16    8 : tunables    0    0    0 : slabdata     38     38      0
Nov 14 01:47:37 dbg: kmalloc-1024         887    896   1024   16    4 : tunables    0    0    0 : slabdata     56     56      0
Nov 14 01:47:37 dbg: kmalloc-512         1264   1264    512   16    2 : tunables    0    0    0 : slabdata     79     79      0
Nov 14 01:47:37 dbg: kmalloc-256         1824   1824    256   16    1 : tunables    0    0    0 : slabdata    114    114      0
Nov 14 01:47:37 dbg: kmalloc-128        37519  40704    128   32    1 : tunables    0    0    0 : slabdata   1272   1272      0
Nov 14 01:47:37 dbg: kmem_cache_node      192    192    128   32    1 : tunables    0    0    0 : slabdata      6      6      0
Nov 14 01:47:37 dbg: kmem_cache           176    176    256   16    1 : tunables    0    0    0 : slabdata     11     11      0
Nov 14 01:47:37 dbg: command: bpm status
Nov 14 01:47:37 kernel: ------------------ BPM Config : Dynamic ----------------
Nov 14 01:47:37 kernel: bpm_max_buf_count                = 28926
Nov 14 01:47:37 kernel: bpm_initial_buf_count            = 5785
Nov 14 01:47:37 kernel: bpm_buf_avail_lower_th           = 512
Nov 14 01:47:37 kernel: bpm_buf_expand_step_size         = 128
Nov 14 01:47:37 kernel: bpm_buf_shrink_step_size         = 32
Nov 14 01:47:37 kernel: bpm_buf_expn_pool_fast_shrink_th = 5785
Nov 14 01:47:37 kernel: bpm_max_skb_count                = 28926
Nov 14 01:47:37 kernel: bpm_initial_skb_count            = 5785
Nov 14 01:47:37 kernel: bpm_skb_avail_lower_th           = 512
Nov 14 01:47:37 kernel: bpm_skb_expand_step_size         = 128
Nov 14 01:47:37 kernel: bpm_skb_shrink_step_size         = 32
Nov 14 01:47:37 kernel: bpm_soak_timer_duration          = 10000
Nov 14 01:47:37 kernel: ----------------------- BPM Status --------------------------
Nov 14 01:47:37 kernel: base pool tot_buf       = 5785
Nov 14 01:47:37 kernel: cur                     = 5767
Nov 14 01:47:37 kernel: exp pool tot_buf        = 1223
Nov 14 01:47:37 kernel: exp pool cur            = 663
Nov 14 01:47:37 kernel: avail                   = 578
Nov 14 01:47:37 kernel: no_buf_err              = 0
Nov 14 01:47:37 kernel: cum_alloc               = 9728
Nov 14 01:47:37 kernel: cum_free                = 3298
Nov 14 01:47:37 kernel: exp cum_alloc           = 1278
Nov 14 01:47:37 kernel: exp cum_free            = 615
Nov 14 01:47:37 kernel: min_availability        = 0
Nov 14 01:47:37 kernel: max_inuse_watermark     = 6448
Nov 14 01:47:37 kernel: max_watermark           = 7040
Nov 14 01:47:37 kernel: buf_expansion_count     = 10
Nov 14 01:47:37 kernel: buf_shrink_count        = 1
Nov 14 01:47:37 kernel: buf_exp_fail_count      = 0
Nov 14 01:47:37 kernel: buf_inthr_alloc_count   = 231
Nov 14 01:47:37 kernel: skb_inthr_alloc_count   = 0
Nov 14 01:47:37 kernel: max_dyn                 = 28926
Nov 14 01:47:37 kernel: -------------------- BPM SKB Pool Status -----------------------
Nov 14 01:47:37 kernel: skb_avail                       = 5785
Nov 14 01:47:37 kernel: skb_total                       = 5785
Nov 14 01:47:37 kernel: skb_bound                       = 28926
Nov 14 01:47:37 kernel: min_skb_avail_cnt               = 5785
Nov 14 01:47:37 kernel: max_skb_wm                      = 5785
Nov 14 01:47:37 kernel: max_inuse_skb_wm                = 0
Nov 14 01:47:37 kernel: skb_alloc_cnt                   = 0
Nov 14 01:47:37 kernel: skb_bpm_alloc_cnt               = 0
Nov 14 01:47:37 kernel: skb_free_cnt                    = 0
Nov 14 01:47:37 kernel: skb_fast_free_cnt               = 0
Nov 14 01:47:37 kernel: skb_fail_cnt                    = 0
Nov 14 01:47:37 kernel: skb_grow_cnt                    = 0
Nov 14 01:47:37 dbg: ==================
Nov 14 01:47:37 kernel: -------------------------------------------------------------
Nov 14 01:47:37 kernel: link down LAN1
Nov 14 01:47:37 scMerlin: Waiting for NTP to sync...
Nov 14 01:47:38 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:47:38 YazDHCP: Trying again with directory [/opt/var/SavedUserIcons]
Nov 14 01:47:38 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:47:38 YazDHCP: Trying again with directory [/opt/var/SavedUserIcons]
Nov 14 01:47:38 YazDHCP: **INFO**:  Backup directory [/opt/var/SavedUserIcons] NOT FOUND.
Nov 14 01:47:38 YazDHCP: Trying again with directory [/jffs/configs/SavedUserIcons]
Nov 14 01:47:38 YazDHCP: *WARNING*: Temporary Backup directory [/jffs/configs/SavedUserIcons]
Nov 14 01:47:38 [MerlinAU.sh] 5076: **ERROR**: The shell script 'MerlinAU.sh' is already running [Lock file: 0 secs.]
Nov 14 01:47:38 [MerlinAU.sh] 5076: Exiting...

@ExtremeFiretop
Copy link
Owner

Not to say I have a skill.... But I have a skill.... ;)

@Martinski4GitHub
Copy link
Collaborator Author

And the verdict is....

My theory was right!!!! :D o.O HOW?!?

...
Nov 14 01:32:31 pppd[5810]: Plugin rp-pppoe.so loaded.
Nov 14 01:32:31 pppd[5810]: RP-PPPoE plugin version 3.11 compiled against pppd 2.4.7
Nov 14 01:32:31 pppd[5839]: pppd 2.4.7 started by Admin, uid 0
Nov 14 01:32:31 rc_service: cfg_server 4844:notify_rc update_nbr
Nov 14 01:32:31 rc_service: waitting "restart_firewall" via  ...
Nov 14 01:32:31 [MerlinAU.sh] 5143: **ERROR**: The shell script 'MerlinAU.sh' is already running [Lock file: 0 secs.]
Nov 14 01:32:31 [MerlinAU.sh] 5143: Exiting...
Nov 14 01:32:31 kernel: SCSI subsystem initialized

Your theory was that the Lock file is essentially surviving a reboot even though it's stored in a temporary virtual filesystem (i.e. created in volatile RAM) and after the reboot, the file is still there not allowing another instance of the script to execute.

Well, that simply cannot happen - it's impossible because of the physics of the volatile RAM chips which (as opposed to non-volatile RAM) cannot retain data stored on it once power is cut off.

Now, if the reboot after the F/W update is not occurring at all... That would be a separate problem to figure out.

@ExtremeFiretop
Copy link
Owner

Now, if the reboot after the F/W update is not occurring at all... That would be a separate problem to figure out.

It has to be occuring, we have a reboot in the script, the router logs indicate a reboot and my network goes down, the RGB lights flash of a firmware upgrade in progress and it comes back online with the new firmware version flashed.

How can it possibly not be rebooting?

Your theory was that the Lock file is essentially surviving a reboot even though it's stored in a temporary virtual filesystem (i.e. created in volatile RAM) and after the reboot, the file is still there not allowing another instance of the script to execute.

I still hold that my theory was lock file related and this is lock file related hehehehahaha :P

@ExtremeFiretop
Copy link
Owner

MERLINAU UPGRADE STARTING:

Nov 14 03:04:22 [MerlinAU.sh] 18666: ---------------------------------------------------------------
Nov 14 03:04:27 [MerlinAU.sh] 18666: Searching for Entware services to stop...
Nov 14 03:04:27 [MerlinAU.sh] 18666: Stopping Entware services...
Nov 14 03:04:27 [MerlinAU.sh] 18666: -----------------------------------------------------------
Nov 14 03:04:27 [MerlinAU.sh] 18666: /opt/etc/init.d/S61unbound
Nov 14 03:04:27 [MerlinAU.sh] 18666: -----------------------------------------------------------
Nov 14 03:04:33 [MerlinAU.sh] 18666: Post-update email notification hook already exists in '/jffs/scripts/services-start' script.
Nov 14 03:04:33 [MerlinAU.sh] 18666: Flashing GT-BE98_PRO_3006_102.2_beta1_nand_squashfs.pkgtb... Please wait for reboot in about 4 minutes or less.
Nov 14 03:04:34 custom_script: Running /jffs/scripts/unmount (args: /tmp/mnt/USB1)
Nov 14 03:04:35 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:35 avahi-daemon[8815]: Files changed, reloading.
Nov 14 03:04:35 avahi-daemon[8815]: Loading service file /tmp/avahi/services/mt-daap.service.
Nov 14 03:04:35 avahi-daemon[8815]: Alias name GT-BE98_Pro: avahi_server_add_cname failure: The requested operation is invalid because redundant
Nov 14 03:04:35 iTunes: daemon is stopped
Nov 14 03:04:35 FTP_Server: daemon is stopped
Nov 14 03:04:35 Samba_Server: smb daemon is stopped
Nov 14 03:04:35 avahi-daemon[8815]: Got SIGTERM, quitting.
Nov 14 03:04:35 avahi-daemon[8815]: avahi-daemon 0.8 exiting.
Nov 14 03:04:39 Timemachine: daemon is stopped
Nov 14 03:04:39 avahi-daemon[29997]: Found user 'nobody' (UID 65534) and group 'nobody' (GID 65534).
Nov 14 03:04:39 avahi-daemon[29997]: Successfully dropped root privileges.
Nov 14 03:04:39 avahi-daemon[29997]: avahi-daemon 0.8 starting up.
Nov 14 03:04:39 avahi-daemon[29997]: Loading service file /tmp/avahi/services/alexa.service.
Nov 14 03:04:39 avahi-daemon[29997]: Loading new alias name GT-BE98_Pro.
Nov 14 03:04:39 avahi-daemon[29997]: New relevant interface br53.IPv4 for mDNS.
Nov 14 03:04:39 avahi-daemon[29997]: New relevant interface br0.IPv4 for mDNS.
Nov 14 03:04:39 avahi-daemon[29997]: New relevant interface lo.IPv4 for mDNS.
Nov 14 03:04:39 avahi-daemon[29997]: Network interface enumeration completed.
Nov 14 03:04:40 avahi-daemon[29997]: Server startup complete. Host name is GT-BE98_Pro.local. Local service cookie is 1543657204.
Nov 14 03:04:40 avahi-daemon[29997]: Alias name GT-BE98_Pro: avahi_server_add_cname failure: The requested operation is invalid because redundant
Nov 14 03:04:40 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:41 avahi-daemon[29997]: Service "GT-BE98_Pro" (/tmp/avahi/services/alexa.service) successfully established.
Nov 14 03:04:41 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:42 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:43 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:44 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:45 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:46 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:47 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:48 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:49 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:50 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:51 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:52 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:53 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:54 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:55 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:56 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:57 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:58 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:04:59 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:00 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:01 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:02 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:03 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:04 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:05 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:06 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:07 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:08 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:09 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:10 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:11 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:12 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:13 ejusb: USB partition unmounted from /tmp/mnt/USB1 fail. (return -1, Device or resource busy)
Nov 14 03:05:14 ejusb: USB partition busy - will unmount ASAP from /tmp/mnt/USB1
Nov 14 03:05:14 kernel: print_req_error: I/O error, dev sda, sector 0
Nov 14 03:05:14 kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Nov 14 03:05:14 kernel: sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Nov 14 03:05:14 kernel: usb 2-1: USB disconnect, device number 2
Nov 14 03:05:14 rc_service: ejusb 29948:notify_rc restart_nasapps
Nov 14 03:05:14 custom_script: Running /jffs/scripts/service-event (args: restart nasapps)
Nov 14 03:05:15 rc_service: httpd 24378:notify_rc stop_upgrade
Nov 14 03:05:15 rc_service: waitting "restart_nasapps" via  ...
Nov 14 03:05:15 avahi-daemon[29997]: Files changed, reloading.
Nov 14 03:05:15 avahi-daemon[29997]: Loading service file /tmp/avahi/services/mt-daap.service.
Nov 14 03:05:15 avahi-daemon[29997]: Alias name GT-BE98_Pro: avahi_server_add_cname failure: The requested operation is invalid because redundant
Nov 14 03:05:15 iTunes: daemon is stopped
Nov 14 03:05:15 FTP_Server: daemon is stopped
Nov 14 03:05:15 Samba_Server: smb daemon is stopped
Nov 14 03:05:15 avahi-daemon[29997]: Got SIGTERM, quitting.
Nov 14 03:05:15 avahi-daemon[29997]: avahi-daemon 0.8 exiting.
Nov 14 03:05:17 Timemachine: daemon is stopped
Nov 14 03:05:17 avahi-daemon[30266]: Found user 'nobody' (UID 65534) and group 'nobody' (GID 65534).
Nov 14 03:05:17 avahi-daemon[30266]: Successfully dropped root privileges.
Nov 14 03:05:17 avahi-daemon[30266]: avahi-daemon 0.8 starting up.
Nov 14 03:05:17 avahi-daemon[30266]: Loading service file /tmp/avahi/services/alexa.service.
Nov 14 03:05:17 avahi-daemon[30266]: Loading new alias name GT-BE98_Pro.
Nov 14 03:05:17 avahi-daemon[30266]: New relevant interface br53.IPv4 for mDNS.
Nov 14 03:05:17 avahi-daemon[30266]: New relevant interface br0.IPv4 for mDNS.
Nov 14 03:05:17 avahi-daemon[30266]: New relevant interface lo.IPv4 for mDNS.
Nov 14 03:05:17 avahi-daemon[30266]: Network interface enumeration completed.
Nov 14 03:05:17 miniupnpd[8816]: shutting down MiniUPnPd
Nov 14 03:05:17 miniupnpd[30268]: HTTP listening on port 35065
Nov 14 03:05:17 miniupnpd[30268]: no HTTP IPv6 address, disabling IPv6
Nov 14 03:05:17 miniupnpd[30268]: Listening for NAT-PMP/PCP traffic on port 5351
Nov 14 03:05:18 custom_script: Running /jffs/scripts/service-event (args: stop upgrade)
Nov 14 03:05:18 avahi-daemon[30266]: Server startup complete. Host name is GT-BE98_Pro.local. Local service cookie is 2367951094.
Nov 14 03:05:18 avahi-daemon[30266]: Alias name GT-BE98_Pro: avahi_server_add_cname failure: The requested operation is invalid because redundant
Nov 14 03:05:18 usb: USB is ejected
Nov 14 03:05:18 BWDPI: force to flush flowcache entries
Nov 14 03:05:18 kernel: IDPfw: Exit IDPfw
Nov 14 03:05:18 kernel: mod epilog takes 0 jiffies
Nov 14 03:05:18 kernel: IDPfw: Exit IDPfw
Nov 14 03:05:18 kernel: Exit chrdev /dev/idpfw with major 191
Nov 14 03:05:18 kernel: udb_core lock_num = 25
Nov 14 03:05:18 kernel:  *** ERROR: [udb_shell_mod_exit:682] Udb static = 0, dynamic = 48
Nov 14 03:05:18 kernel: Exit chrdev /dev/idp with major 190
Nov 14 03:05:18 BWDPI: rollback fc
Nov 14 03:05:18 WEBDAV_Server: daemon is stopped
Nov 14 03:05:18 WEBDAV_Server: arpping daemon is stopped
Nov 14 03:05:18 UAM_Server: daemon is stoped
Nov 14 03:05:18 iTunes: daemon is stopped
Nov 14 03:05:18 FTP_Server: daemon is stopped
Nov 14 03:05:18 Samba_Server: smb daemon is stopped
Nov 14 03:05:18 Timemachine: daemon is stopped
Nov 14 03:05:18 WEBDAV_Server: daemon is stopped
Nov 14 03:05:18 hour_monitor: dpi engine doesn't exist
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver ipheth
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver qmi_wwan
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver cdc_wdm
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver rndis_host
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver cdc_ether
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver ax88179_178a
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver asix
Nov 14 03:05:18 kernel: usbcore: deregistering interface driver cdc_acm
Nov 14 03:05:18 kernel: cdrom: Uniform CD-ROM driver unloaded
Nov 14 03:05:18 iTunes: daemon is stopped
Nov 14 03:05:18 FTP_Server: daemon is stopped
Nov 14 03:05:18 Samba_Server: smb daemon is stopped
Nov 14 03:05:19 Timemachine: daemon is stopped
Nov 14 03:05:19 avahi-daemon[30266]: Service "GT-BE98_Pro" (/tmp/avahi/services/alexa.service) successfully established.
Nov 14 03:05:20 ntpd: Stopped ntpd
Nov 14 03:05:21 miniupnpd[30268]: shutting down MiniUPnPd
Nov 14 03:05:21 avahi-daemon[30266]: Got SIGTERM, quitting.
Nov 14 03:05:21 avahi-daemon[30266]: avahi-daemon 0.8 exiting.
Nov 14 03:05:21 disk_monitor: Finish
Nov 14 03:05:21 Mastiff: Got SIGTERM

DISCONNECT FROM SSH LOGS:

Nov 14 03:05:23 dropbear[17738]: Exit (Admin) from <192.168.50.163:61417>: Terminated by signal
Nov 14 03:05:23 dropbear[11084]: Exit (Admin) from <192.168.50.163:60366>: Terminated by signal
Nov 14 03:05:23 dropbear[4886]: Early exit: Terminated by signal
Nov 14 03:05:23 kernel: Buffer I/O error on dev sda1, logical block 38830080, lost sync page write
Nov 14 03:05:23 kernel: JBD2: Error -5 detected when updating journal superblock for sda1-8.
Nov 14 03:05:23 kernel: Aborting journal on device sda1-8.
Nov 14 03:05:23 kernel: Buffer I/O error on dev sda1, logical block 38830080, lost sync page write
Nov 14 03:05:23 kernel: JBD2: Error -5 detected when updating journal superblock for sda1-8.
Nov 14 03:05:23 kernel: echo (30665): drop_caches: 1

UPGRADE SIGNAL STARTING:

Nov 14 03:06:12 rc_service: httpd 24378:notify_rc start_upgrade
Nov 14 03:06:12 custom_script: Running /jffs/scripts/service-event (args: start upgrade)

STOPPING LOGS:

Nov 14 03:06:12 custom_script: Running /jffs/scripts/services-stop
Nov 14 03:06:12 amtm routerdate: Preserving router date before reboot (2024-11-14 08:06:12) UTC time.
Nov 14 03:06:14 WEBDAV_Server: daemon is stopped
Nov 14 03:06:14 FTP_Server: daemon is stopped
Nov 14 03:06:14 Samba_Server: smb daemon is stopped
Nov 14 03:06:14 Timemachine: daemon is stopped
Nov 14 03:06:14 dnsmasq[27734]: exiting on receipt of SIGTERM
Nov 14 03:06:14 dnsmasq[27729]: exiting on receipt of SIGTERM
Nov 14 03:06:14 hostapd: wl0: STA fc:34:97:b2:5e:b8 IEEE 802.11: disassociated
Nov 14 03:06:14 kernel: wfd_unregisterdevice Successfully unregistered ifidx 2 wfd_idx 0
Nov 14 03:06:14 kernel: br0: port 11(wds0.0.1.0) entered disabled state
Nov 14 03:06:14 kernel: device wds0.0.1 left promiscuous mode
Nov 14 03:06:14 kernel: br53: port 12(wds0.0.1.52) entered disabled state
Nov 14 03:06:14 kernel: Freeing devid[2110] for wds0.0.1
Nov 14 03:06:14 kernel: Freeing devid[2111] for wds0.0.1.0
Nov 14 03:06:14 kernel: br0: port 11(wds0.0.1.0) entered disabled state
Nov 14 03:06:14 kernel: Freeing devid[2112] for wds0.0.1.52
Nov 14 03:06:14 kernel: br53: port 12(wds0.0.1.52) entered disabled state
Nov 14 03:06:14 hostapd: wl2: STA 18:26:54:c4:4c:7a IEEE 802.11: disassociated
Nov 14 03:06:14 hostapd: wl0: STA c0:ee:fb:a5:71:62 IEEE 802.11: disassociated
Nov 14 03:06:14 hostapd: wl2: STA 00:41:0e:23:06:27 IEEE 802.11: disassociated
Nov 14 03:06:14 hostapd: wl0: STA 70:cf:49:b4:31:83 IEEE 802.11: disassociated
Nov 14 03:06:14 hostapd: wl2: STA ac:c0:48:70:1b:d1 IEEE 802.11: disassociated
Nov 14 03:06:14 hostapd: wl3: STA 50:8b:b9:00:19:de IEEE 802.11: disassociated
Nov 14 03:06:14 kernel: wfd_unregisterdevice Successfully unregistered ifidx 2 wfd_idx 3
Nov 14 03:06:14 kernel: br0: port 9(wds3.0.1.0) entered disabled state
Nov 14 03:06:14 kernel: device wds3.0.1 left promiscuous mode
Nov 14 03:06:14 kernel: br53: port 11(wds3.0.1.52) entered disabled state
Nov 14 03:06:14 kernel: Freeing devid[2107] for wds3.0.1
Nov 14 03:06:14 kernel: Freeing devid[2108] for wds3.0.1.0
Nov 14 03:06:14 kernel: br0: port 9(wds3.0.1.0) entered disabled state
Nov 14 03:06:14 kernel: Freeing devid[2109] for wds3.0.1.52
Nov 14 03:06:14 kernel: br53: port 11(wds3.0.1.52) entered disabled state
Nov 14 03:06:14 kernel: CFGP2P-ERROR) wl_cfgp2p_find_ndev : 
Nov 14 03:06:14 kernel:  p2p inactive
Nov 14 03:06:15 kernel: wfd_unregisterdevice Successfully unregistered ifidx 1 wfd_idx 0
Nov 14 03:06:15 kernel: CFG80211-ERROR) wl_add_remove_eventmsg : 
Nov 14 03:06:15 kernel: Get event_msgs error (-19)
Nov 14 03:06:15 kernel: br53: port 2(wl0.1) entered disabled state
Nov 14 03:06:15 kernel: ^[[0;31mdhd_pktfwd_lut_lkup: dhd_pktfwd_lut_lkup: pool 0 and unit 15 mismatched
Nov 14 03:06:15 kernel: ^[[0m
Nov 14 03:06:15 kernel: Freeing devid[2078] for wl0.1
Nov 14 03:06:15 kernel: device wl0.1 left promiscuous mode
Nov 14 03:06:15 kernel: br53: port 2(wl0.1) entered disabled state
Nov 14 03:06:15 kernel: ^[[0;31mdhd_pktfwd_lut_lkup: dhd_pktfwd_lut_lkup: pool 0 and unit 15 mismatched
Nov 14 03:06:15 kernel: ^[[0m
Nov 14 03:06:15 kernel: CFGP2P-ERROR) wl_cfgp2p_find_ndev : 
Nov 14 03:06:15 kernel:  p2p inactive
Nov 14 03:06:15 kernel: CFG80211-ERROR) wl_event_handler : 
Nov 14 03:06:15 kernel: No wdev corresponding to bssidx: 0x1 found! Ignoring event.
Nov 14 03:06:15 kernel: CFG80211-ERROR) wl_event_handler : 
Nov 14 03:06:15 kernel: No wdev corresponding to bssidx: 0x1 found! Ignoring event.
Nov 14 03:06:16 kernel: CFG80211-ERROR) wl_cfg80211_del_iface : 
Nov 14 03:06:16 kernel: timeout in waiting IF_DEL event
Nov 14 03:06:16 kernel: wfd_unregisterdevice Successfully unregistered ifidx 1 wfd_idx 3
Nov 14 03:06:16 kernel: CFG80211-ERROR) wl_add_remove_eventmsg : 
Nov 14 03:06:16 kernel: Get event_msgs error (-19)
Nov 14 03:06:16 kernel: br53: port 1(wl3.1) entered disabled state
Nov 14 03:06:16 kernel: ^[[0;31mdhd_pktfwd_lut_lkup: dhd_pktfwd_lut_lkup: pool 3 and unit 15 mismatched
Nov 14 03:06:16 kernel: ^[[0m
Nov 14 03:06:16 kernel: Freeing devid[2080] for wl3.1
Nov 14 03:06:16 kernel: device wl3.1 left promiscuous mode
Nov 14 03:06:16 kernel: br53: port 1(wl3.1) entered disabled state
Nov 14 03:06:16 kernel: CFG80211-ERROR) wl_event_handler : 
Nov 14 03:06:16 kernel: No wdev corresponding to bssidx: 0x1 found! Ignoring event.
Nov 14 03:06:16 kernel: CFG80211-ERROR) wl_event_handler : 
Nov 14 03:06:16 kernel: No wdev corresponding to bssidx: 0x1 found! Ignoring event.

MORE STOPPING LOGS:

Nov 14 03:06:18 haveged: haveged: Stopping due to signal 15
Nov 14 03:06:18 pppd[5927]: Hangup (SIGHUP)
Nov 14 03:06:18 pppd[5927]: Terminating on signal 15
Nov 14 03:06:18 pppd[5927]: Connect time 10.5 minutes.
Nov 14 03:06:18 pppd[5927]: Sent 1206866676 bytes, received 2107346501 bytes.
Nov 14 03:06:18 pppd[5927]: Connection terminated.
Nov 14 03:06:18 kernel: Freeing devid[2097] for ppp0
Nov 14 03:06:18 pppd[5927]: Failed to disconnect PPPoE socket: 114 Operation already in progress
Nov 14 03:06:18 pppd[5927]: Sent PADT
Nov 14 03:06:18 pppd[5927]: Exit.
Nov 14 03:06:22 kernel: device eth0.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 7(eth0.52) entered disabled state
Nov 14 03:06:22 kernel: device eth1.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 8(eth1.52) entered disabled state
Nov 14 03:06:22 kernel: device eth2.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 9(eth2.52) entered disabled state
Nov 14 03:06:22 kernel: device eth3.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 10(eth3.52) entered disabled state
Nov 14 03:06:22 kernel: device wl0.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 3(wl0.52) entered disabled state
Nov 14 03:06:22 kernel: device wl1.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 4(wl1.52) entered disabled state
Nov 14 03:06:22 kernel: device wl2.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 5(wl2.52) entered disabled state
Nov 14 03:06:22 kernel: device wl3.52 left promiscuous mode
Nov 14 03:06:22 kernel: br53: port 6(wl3.52) entered disabled state
Nov 14 03:06:22 kernel: Freeing devid[2093] for br53
Nov 14 03:06:22 kernel: Freeing devid[2082] for wl0.52
Nov 14 03:06:22 kernel: device wl0.0 left promiscuous mode
Nov 14 03:06:22 kernel: device wl0 left promiscuous mode
Nov 14 03:06:22 kernel: br0: port 5(wl0.0) entered disabled state
Nov 14 03:06:22 kernel: Freeing devid[2081] for wl0.0
Nov 14 03:06:22 kernel: br0: port 5(wl0) entered blocking state
Nov 14 03:06:22 kernel: br0: port 5(wl0) entered disabled state
Nov 14 03:06:22 kernel: device wl0 entered promiscuous mode
Nov 14 03:06:22 kernel: br0: port 5(wl0) entered blocking state
Nov 14 03:06:22 kernel: br0: port 5(wl0) entered forwarding state
Nov 14 03:06:22 kernel: Freeing devid[2084] for wl1.52
Nov 14 03:06:22 kernel: device wl1.0 left promiscuous mode
Nov 14 03:06:22 kernel: device wl1 left promiscuous mode
Nov 14 03:06:22 kernel: br0: port 6(wl1.0) entered disabled state
Nov 14 03:06:22 kernel: Freeing devid[2083] for wl1.0
Nov 14 03:06:22 kernel: br0: port 6(wl1) entered blocking state
Nov 14 03:06:22 kernel: br0: port 6(wl1) entered disabled state
Nov 14 03:06:22 kernel: device wl1 entered promiscuous mode
Nov 14 03:06:22 kernel: br0: port 6(wl1) entered blocking state
Nov 14 03:06:22 kernel: br0: port 6(wl1) entered forwarding state
Nov 14 03:06:22 kernel: Freeing devid[2086] for wl2.52
Nov 14 03:06:22 kernel: device wl2.0 left promiscuous mode
Nov 14 03:06:22 kernel: device wl2 left promiscuous mode
Nov 14 03:06:22 kernel: br0: port 7(wl2.0) entered disabled state
Nov 14 03:06:22 kernel: Freeing devid[2085] for wl2.0
Nov 14 03:06:22 kernel: br0: port 7(wl2) entered blocking state
Nov 14 03:06:22 kernel: br0: port 7(wl2) entered disabled state
Nov 14 03:06:22 kernel: device wl2 entered promiscuous mode
Nov 14 03:06:22 kernel: br0: port 7(wl2) entered blocking state
Nov 14 03:06:22 kernel: br0: port 7(wl2) entered forwarding state
Nov 14 03:06:22 kernel: Freeing devid[2088] for wl3.52
Nov 14 03:06:22 kernel: device wl3.0 left promiscuous mode
Nov 14 03:06:22 kernel: device wl3 left promiscuous mode
Nov 14 03:06:22 kernel: br0: port 8(wl3.0) entered disabled state
Nov 14 03:06:22 kernel: Freeing devid[2087] for wl3.0
Nov 14 03:06:22 kernel: br0: port 8(wl3) entered blocking state
Nov 14 03:06:22 kernel: br0: port 8(wl3) entered disabled state
Nov 14 03:06:22 kernel: device wl3 entered promiscuous mode
Nov 14 03:06:22 kernel: br0: port 8(wl3) entered blocking state
Nov 14 03:06:22 kernel: br0: port 8(wl3) entered forwarding state
Nov 14 03:06:22 kernel: Freeing devid[2089] for eth0.52
Nov 14 03:06:22 kernel: Freeing devid[2090] for eth1.52
Nov 14 03:06:22 kernel: Freeing devid[2091] for eth2.52
Nov 14 03:06:22 kernel: Freeing devid[2092] for eth3.52
Nov 14 03:06:22 kernel: vlan_accept_all_byports
Nov 14 03:06:22 kernel: set reg 1538 as f33
Nov 14 03:06:22 kernel: set reg 1638 as f33
Nov 14 03:06:22 kernel: set reg 1738 as f33
Nov 14 03:06:22 kernel: set reg 1838 as f33
Nov 14 03:06:22 kernel: set reg 1938 as f33
Nov 14 03:06:22 kernel: set reg 1a38 as f33
Nov 14 03:06:22 kernel: createVlan_nopvid_mbr_untag_cpu : vid = 0, prio = 0, mbrmsk = 0xD8, untagmsk = 0xD8
Nov 14 03:06:22 kernel: set reg 1538 as f33
Nov 14 03:06:22 kernel: set reg 1638 as f33
Nov 14 03:06:22 kernel: set reg 1738 as f33
Nov 14 03:06:22 kernel: set reg 1838 as f33
Nov 14 03:06:22 kernel: set reg 1938 as f33
Nov 14 03:06:22 kernel: set reg 1a38 as f33
Nov 14 03:06:22 kernel: set_ports_pvid:00000000
Nov 14 03:06:22 kernel: set reg 1538 as f33
Nov 14 03:06:22 kernel: set reg 1638 as f33
Nov 14 03:06:22 kernel: set reg 1738 as f33
Nov 14 03:06:22 kernel: set reg 1838 as f33
Nov 14 03:06:22 kernel: set reg 1938 as f33
Nov 14 03:06:22 kernel: set reg 1a38 as f33
Nov 14 03:06:22 kernel: br0: port 8(wl3) entered disabled state
Nov 14 03:06:22 kernel: br0: port 7(wl2) entered disabled state
Nov 14 03:06:22 kernel: br0: port 6(wl1) entered disabled state
Nov 14 03:06:22 kernel: br0: port 5(wl0) entered disabled state
Nov 14 03:06:22 kernel: br0: port 2(eth1) entered disabled state
Nov 14 03:06:22 kernel: br0: port 1(eth0) entered disabled state
Nov 14 03:06:22 kernel: br0: port 10(wl1.4) entered disabled state
Nov 14 03:06:23 kernel: port_generic_stop 604 skip turnning off power on eth0 here
Nov 14 03:06:23 kernel: device eth0 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 1(eth0) entered disabled state
Nov 14 03:06:23 kernel: port_generic_stop 604 skip turnning off power on eth1 here
Nov 14 03:06:23 kernel: device eth1 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 2(eth1) entered disabled state
Nov 14 03:06:23 kernel: port_generic_stop 604 skip turnning off power on eth2 here
Nov 14 03:06:23 kernel: device eth2 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 3(eth2) entered disabled state
Nov 14 03:06:23 kernel: port_generic_stop 604 skip turnning off power on eth3 here
Nov 14 03:06:23 kernel: device eth3 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 4(eth3) entered disabled state
Nov 14 03:06:23 kernel: device wl0 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 5(wl0) entered disabled state
Nov 14 03:06:23 kernel: device wl1 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 6(wl1) entered disabled state
Nov 14 03:06:23 kernel: device wl2 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 7(wl2) entered disabled state
Nov 14 03:06:23 kernel: device wl3 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 8(wl3) entered disabled state
Nov 14 03:06:23 kernel: device wl1.4 left promiscuous mode
Nov 14 03:06:23 kernel: br0: port 10(wl1.4) entered disabled state
Nov 14 03:06:23 kernel: Freeing devid[2077] for br0
Nov 14 03:06:28 FTP_Server: daemon is stopped
Nov 14 03:06:28 Samba_Server: smb daemon is stopped
Nov 14 03:06:28 Timemachine: daemon is stopped
Nov 14 03:06:28 FTP_Server: daemon is stopped
Nov 14 03:06:28 Samba_Server: smb daemon is stopped
Nov 14 03:06:28 Timemachine: daemon is stopped
Nov 14 03:06:28 WEBDAV_Server: daemon is stopped
Nov 14 03:06:28 syslogd exiting

DONE

STARTING:

Nov 14 03:06:12 syslogd started: BusyBox v1.25.1
Nov 14 03:06:12 kernel: klogd started: BusyBox v1.25.1 (2024-10-12 12:55:29 EDT)
Nov 14 03:06:12 kernel: Booting Linux on physical CPU 0x0000000000 [0x420f1000]
Nov 14 03:06:12 kernel: Linux version 4.19.275 (root@asus) (gcc version 10.3.0 (Buildroot 2021.02.4)) #1 SMP PREEMPT Sat Oct 12 12:57:18 EDT 2024
Nov 14 03:06:12 kernel: Machine model: Broadcom-v8A
Nov 14 03:06:12 kernel: Reserved memory: created CMA memory pool at 0x000000006d000000, size 304 MiB
Nov 14 03:06:12 kernel: OF: reserved mem: initialized node dt_reserved_cma, compatible id shared-dma-pool
Nov 14 03:06:12 kernel: cma: Reserved 168 MiB at 0x0000000062800000
Nov 14 03:06:12 kernel: psci: probing for conduit method from DT.
Nov 14 03:06:12 kernel: psci: PSCIv1.1 detected in firmware.
Nov 14 03:06:12 kernel: psci: Using standard PSCI v0.2 function IDs
Nov 14 03:06:12 kernel: psci: MIGRATE_INFO_TYPE not supported.
Nov 14 03:06:12 kernel: psci: SMC Calling Convention v1.0
Nov 14 03:06:12 kernel: percpu: Embedded 32 pages/cpu s93272 r8192 d29608 u131072
Nov 14 03:06:12 kernel: Detected VIPT I-cache on CPU0
Nov 14 03:06:12 kernel: CPU features: enabling workaround for ARM erratum 843419
Nov 14 03:06:12 kernel: CPU features: enabling workaround for ARM erratum 845719
Nov 14 03:06:12 kernel: ARM_SMCCC_ARCH_WORKAROUND_1 missing from firmware
Nov 14 03:06:12 kernel: CPU features: detected: Kernel page table isolation (KPTI)
Nov 14 03:06:12 kernel: Built 1 zonelists, mobility grouping on.  Total pages: 516096
Nov 14 03:06:12 kernel: Kernel command line: coherent_pool=4M cpuidle_sysfs_switch pci=pcie_bus_safe console=ttyAMA0,115200  rootwait rng_core.default_quality=1024 mtdparts=brcmnand.0:2097152(loader),265289728@2097152(image) root=/dev/ubiblock0_4 ubi.mtd=image ubi.block=0,4 rootfstype=squashfs cma=168M
Nov 14 03:06:12 kernel: Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
Nov 14 03:06:12 kernel: Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
Nov 14 03:06:12 kernel: Memory: 1563436K/2097152K available (7742K kernel code, 530K rwdata, 1776K rodata, 1280K init, 767K bss, 50388K reserved, 483328K cma-reserved)
Nov 14 03:06:12 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Nov 14 03:06:12 kernel: rcu: Preemptible hierarchical RCU implementation.
Nov 14 03:06:12 kernel: 	Tasks RCU enabled.
Nov 14 03:06:12 kernel: NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
Nov 14 03:06:12 kernel: GIC: Using split EOI/Deactivate mode
Nov 14 03:06:12 kernel: arch_timer: cp15 timer(s) running at 50.00MHz (phys).
Nov 14 03:06:12 kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xb8812736b, max_idle_ns: 440795202655 ns
Nov 14 03:06:12 kernel: sched_clock: 56 bits at 50MHz, resolution 20ns, wraps every 4398046511100ns
Nov 14 03:06:12 kernel: Console: colour dummy device 80x25
Nov 14 03:06:12 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 100.00 BogoMIPS (lpj=50000)
Nov 14 03:06:12 kernel: pid_max: default: 32768 minimum: 301
Nov 14 03:06:12 kernel: Mount-cache hash table entries: 4096 (order: 3, 32768 bytes)
Nov 14 03:06:12 kernel: Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes)
Nov 14 03:06:12 kernel: ASID allocator initialised with 32768 entries
Nov 14 03:06:12 kernel: rcu: Hierarchical SRCU implementation.
Nov 14 03:06:12 kernel: CCI-500 hardware cache coherency enabled
Nov 14 03:06:12 kernel: bootloader version  U-Boot2019.07(10/12/2024-12:56:19-0400)50404p2@450432
Nov 14 03:06:12 kernel: BoardId [GT-BE98PRO], NVRAM_ULBOARDSTUFFOPTION=0 
Nov 14 03:06:12 kernel: smp: Bringing up secondary CPUs ...
Nov 14 03:06:12 kernel: Detected VIPT I-cache on CPU1
Nov 14 03:06:12 kernel: CPU1: Booted secondary processor 0x0000000001 [0x420f1000]
Nov 14 03:06:12 kernel: Detected VIPT I-cache on CPU2
Nov 14 03:06:12 kernel: CPU2: Booted secondary processor 0x0000000002 [0x420f1000]
Nov 14 03:06:12 kernel: Detected VIPT I-cache on CPU3
Nov 14 03:06:12 kernel: CPU3: Booted secondary processor 0x0000000003 [0x420f1000]
Nov 14 03:06:12 kernel: smp: Brought up 1 node, 4 CPUs
Nov 14 03:06:12 kernel: SMP: Total of 4 processors activated.
Nov 14 03:06:12 kernel: CPU features: detected: 32-bit EL0 Support
Nov 14 03:06:12 kernel: CPU features: emulated: Privileged Access Never (PAN) using TTBR0_EL1 switching
Nov 14 03:06:12 kernel: CPU: All CPU(s) started at EL2
Nov 14 03:06:12 kernel: alternatives: patching kernel code
Nov 14 03:06:12 kernel: devtmpfs: initialized
Nov 14 03:06:12 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
Nov 14 03:06:12 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes)
Nov 14 03:06:12 kernel: pinctrl core: initialized pinctrl subsystem
Nov 14 03:06:12 kernel: size of sk_buff 576
Nov 14 03:06:12 kernel: offset of cb in sk_buff 392
Nov 14 03:06:12 kernel: NET: Registered protocol family 16
Nov 14 03:06:12 kernel: OTP driver initcall
Nov 14 03:06:12 kernel: OTP driver scanning DT
Nov 14 03:06:12 kernel: Strap Register: 0x7fffd3c3
Nov 14 03:06:12 kernel: cpuidle: using governor menu
Nov 14 03:06:12 kernel: PMC driver initcall
Nov 14 03:06:12 kernel: PMC driver scanning DT
Nov 14 03:06:12 kernel:  not match PMC
Nov 14 03:06:12 kernel: pmc match PMC brcm,bca-pmc-3-2
Nov 14 03:06:12 kernel:      Remapping PMC IO memories...
Nov 14 03:06:12 kernel:              phys              virt          size
Nov 14 03:06:12 kernel:      0x00000000ffb01018 0xffffff8008150018 0x00005080
Nov 14 03:06:12 kernel:      0x00000000ffb20000 0xffffff8008025000 0x00000240
Nov 14 03:06:12 kernel:      0x00000000ffb00400 0xffffff800802d400 0x000005d0
Nov 14 03:06:12 kernel:      0x00000000ffb80000 0xffffff8008035000 0x00001000
Nov 14 03:06:12 kernel: pmc_init:PMC using DQM mode
Nov 14 03:06:12 kernel: BCM UBUS Driver initcall
Nov 14 03:06:12 kernel: ubus systop  		 phys addr 0x0000000083000000 virt addr 0xffffff8008045000
Nov 14 03:06:12 kernel: ubus registration  	 phys addr 0x0000000083000200 virt addr 0xffffff800804d200
Nov 14 03:06:12 kernel: ubus coherency 		 phys addr 0x00000000810a0400 virt addr 0xffffff8008055400
Nov 14 03:06:12 kernel: ubus mst node BIU	 phys addr 0x0000000083020000 virt addr 0xffffff8008158000
Nov 14 03:06:12 kernel: ubus mst node PER	 phys addr 0x0000000083010000 virt addr 0xffffff8008160000
Nov 14 03:06:12 kernel: ubus mst node USB	 phys addr 0x0000000083018000 virt addr 0xffffff8008168000
Nov 14 03:06:12 kernel: ubus mst node PCIE0	 phys addr 0x0000000083030000 virt addr 0xffffff8008170000
Nov 14 03:06:12 kernel: ubus mst node PCIE1	 phys addr 0x0000000083038000 virt addr 0xffffff8008178000
Nov 14 03:06:12 kernel: ubus mst node PCIE2	 phys addr 0x0000000083040000 virt addr 0xffffff8008180000
Nov 14 03:06:12 kernel: ubus mst node PCIE3	 phys addr 0x0000000083048000 virt addr 0xffffff8008188000
Nov 14 03:06:12 kernel: ubus mst node DMA0	 phys addr 0x0000000083058000 virt addr 0xffffff8008190000
Nov 14 03:06:12 kernel: ubus mst node DMA1	 phys addr 0x0000000083060000 virt addr 0xffffff8008198000
Nov 14 03:06:12 kernel: ubus mst node DMA2	 phys addr 0x0000000083070000 virt addr 0xffffff80081a0000
Nov 14 03:06:12 kernel: ubus mst node RQ0	 phys addr 0x0000000083078000 virt addr 0xffffff80081a8000
Nov 14 03:06:12 kernel: ubus mst node RQ1	 phys addr 0x0000000083080000 virt addr 0xffffff80081b0000
Nov 14 03:06:12 kernel: ubus mst node QM	 phys addr 0x0000000083050000 virt addr 0xffffff80081b8000
Nov 14 03:06:12 kernel: ubus mst node SPU	 phys addr 0x0000000083028000 virt addr 0xffffff80081c0000
Nov 14 03:06:12 kernel: ubus mst node MPM	 phys addr 0x0000000083088000 virt addr 0xffffff80081c8000
Nov 14 03:06:12 kernel: DMA: preallocated 4096 KiB pool for atomic allocations
Nov 14 03:06:12 kernel: Serial: AMBA PL011 UART driver
Nov 14 03:06:12 kernel: Powering on XRDP core...
Nov 14 03:06:12 kernel: Toggle reset of XRDP core...
Nov 14 03:06:12 kernel: bcm_rsvmem plat_rsvmem_cached_device: assigned reserved memory node dt_reserved_cma
Nov 14 03:06:12 kernel: reserved CMA memory bufmem virt addr ffffffc06d000000 phys addr 0x000000006d000000 size 0x10000000 cached=1
Nov 14 03:06:12 kernel: reserved CMA memory rnrmem virt addr ffffffc07d000000 phys addr 0x000000007d000000 size 0xc00000 cached=1
Nov 14 03:06:12 kernel: bcm_rsvmem plat_rsvmem_uncached_device: assigned reserved memory node dt_reserved_cma
Nov 14 03:06:12 kernel: reserved CMA memory dhd0 virt addr ffffff80091df000 phys addr 0x000000007dc00000 size 0xb00000 cached=0
Nov 14 03:06:12 kernel: reserved CMA memory dhd1 virt addr ffffff8009ce0000 phys addr 0x000000007e700000 size 0xb00000 cached=0
Nov 14 03:06:12 kernel: reserved CMA memory dhd2 virt addr ffffff800a7e1000 phys addr 0x000000007f200000 size 0xb00000 cached=0
Nov 14 03:06:12 kernel: IRQ virt [10] registered as pmc temp warning interrupt
Nov 14 03:06:12 kernel: brcm_otp_init entry
Nov 14 03:06:12 kernel: bcm-bca-gpio ff800500.gpioc: Setting up BCA GPIO
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_0 HWIrq 79 virq 58
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_1 HWIrq 80 virq 59
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_2 HWIrq 81 virq 60
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_3 HWIrq 82 virq 61
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_4 HWIrq 83 virq 62
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_5 HWIrq 84 virq 63
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_6 HWIrq 85 virq 64
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Ext_Int_7 HWIrq 86 virq 65
Nov 14 03:06:12 kernel: bca_extintr ff800004.bca_extintr0: Readed resouce bca_extintr0 start 0xff800004 end 0xff80004b
Nov 14 03:06:12 kernel: ff812000.serial0: ttyAMA0 at MMIO 0xff812000 (irq = 66, base_baud = 0) is a PL011 rev3
Nov 14 03:06:12 kernel: console [ttyAMA0] enabled
Nov 14 03:06:12 kernel: bcm-bca-cled-ctrl ff803000.led_ctrl: max supported leds 64[64]
Nov 14 03:06:12 kernel: bcm-bca-cled-ctrl ff803000.led_ctrl:  Parallel CLED interface found
Nov 14 03:06:12 kernel: cryptd: max_cpu_qlen set to 1000
Nov 14 03:06:12 kernel: map_hw_timer_interrupt,162: interrupt_id 68
Nov 14 03:06:12 kernel: map_hw_timer_interrupt,162: interrupt_id 69
Nov 14 03:06:12 kernel: map_hw_timer_interrupt,162: interrupt_id 70
Nov 14 03:06:12 kernel: map_hw_timer_interrupt,162: interrupt_id 71
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_2: led 2 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_3: led 3 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_4: led 4 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_5: led 5 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_7: led 7 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_8: led 8 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_14: led 14 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_15: led 15 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:sw_parallel_led_16: led 16 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_1: led 1 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_17: led 17 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_43: led 43 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_47: led 47 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_50: led 50 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_48: led 48 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_14: led 14 registered
Nov 14 03:06:12 kernel: bcm-bca-leds ff803000.led_ctrl:led_gpio_62: led 62 registered
Nov 14 03:06:12 kernel: bcm-dgasp ff85a004.dying_gasp: Dying Gasp platform device brcm,dgasp-periph matched
Nov 14 03:06:12 kernel: dg-periph-reg: 0x00000000ff85a004<-->0xffffff8008105004:0x00000000
Nov 14 03:06:12 kernel: dg-get-otp-trim: 0x00000001
Nov 14 03:06:12 kernel: otp-dg-trim    : 0x00000003
Nov 14 03:06:12 kernel: dg-get-otp-hys : 0x00000001
Nov 14 03:06:12 kernel: otp-dg-hys     : 0x00000002
Nov 14 03:06:12 kernel: DYING GASP IRQ Initialized and Enabled
Nov 14 03:06:12 kernel: Broadcom GBPMv0.1 initialized
Nov 14 03:06:12 kernel: Broadcom IQoS v1.0 initialized
Nov 14 03:06:12 kernel: Broadcom Logger v0.1
Nov 14 03:06:12 kernel: Char device /dev/bcmnet(251) registered
Nov 14 03:06:12 kernel: Assigning idx[1] for lo
Nov 14 03:06:12 kernel: skb_free_task created successfully with start budget 32, period 10ms
Nov 14 03:06:12 kernel: ^[[0;34mBLOG v3.0 Initialized^[[0m
Nov 14 03:06:12 kernel: BLOG Rule v1.0 Initialized
Nov 14 03:06:12 kernel:  create_bcm_tcp_task:348 bind_mask:0x6
Nov 14 03:06:12 kernel: bcm_tcp_task created successfully with budget 256 ,cpumask:0x6
Nov 14 03:06:12 kernel: clocksource: Switched to clocksource arch_sys_counter
Nov 14 03:06:12 kernel: NET: Registered protocol family 2
Nov 14 03:06:12 kernel: IP idents hash table entries: 32768 (order: 6, 262144 bytes)
Nov 14 03:06:12 kernel: tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes)
Nov 14 03:06:12 kernel: TCP established hash table entries: 16384 (order: 5, 131072 bytes)
Nov 14 03:06:12 kernel: TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
Nov 14 03:06:12 kernel: TCP: Hash tables configured (established 16384 bind 16384)
Nov 14 03:06:12 kernel: UDP hash table entries: 1024 (order: 3, 32768 bytes)
Nov 14 03:06:12 kernel: UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
Nov 14 03:06:12 kernel: NET: Registered protocol family 1
Nov 14 03:06:12 kernel: Assigning idx[2] for blogtcp_local
Nov 14 03:06:12 kernel: blogtcp_local netdev registered successfully 
Nov 14 03:06:12 kernel: Initialise system trusted keyrings
Nov 14 03:06:12 kernel: workingset: timestamp_bits=62 max_order=19 bucket_order=0
Nov 14 03:06:12 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher
Nov 14 03:06:12 kernel: jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
Nov 14 03:06:12 kernel: fuse init (API version 7.27)
Nov 14 03:06:12 kernel: Key type asymmetric registered
Nov 14 03:06:12 kernel: Asymmetric key parser 'x509' registered
Nov 14 03:06:12 kernel: io scheduler noop registered (default)
Nov 14 03:06:12 kernel: io scheduler mq-deadline registered
Nov 14 03:06:12 kernel: io scheduler kyber registered
Nov 14 03:06:12 kernel: iproc-rng200 ff800b80.rng: hwrng registered
Nov 14 03:06:12 kernel: brd: module loaded
Nov 14 03:06:12 kernel: loop: module loaded
Nov 14 03:06:12 kernel: nand: device found, Manufacturer ID: 0xc2, Chip ID: 0xda
Nov 14 03:06:12 kernel: nand: Macronix MX30LF2G28AD
Nov 14 03:06:12 kernel: nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 128
Nov 14 03:06:12 kernel: bcm63xx_nand ff801800.nand: Adjust timing_1 to 0x6532845b, timing_2 to 0x00091e94
Nov 14 03:06:12 kernel: bcm63xx_nand ff801800.nand: detected 256MiB total, 128KiB blocks, 2KiB pages, 27B OOB, 8-bit, BCH-8
Nov 14 03:06:12 kernel: Bad block table found at page 131008, version 0x02
Nov 14 03:06:12 kernel: Bad block table found at page 130944, version 0x02
Nov 14 03:06:12 kernel: nand_read_bbt: bad block at 0x000008960000
Nov 14 03:06:12 kernel: 2 cmdlinepart partitions found on MTD device brcmnand.0
Nov 14 03:06:12 kernel: Creating 2 MTD partitions on "brcmnand.0":
Nov 14 03:06:12 kernel: 0x000000000000-0x000000200000 : "loader"
Nov 14 03:06:12 kernel: 0x000000200000-0x00000ff00000 : "image"
Nov 14 03:06:12 kernel: bcmbca-hsspi ff801000.spi: Broadcom BCMBCA High Speed SPI Controller driver
Nov 14 03:06:12 kernel: bcmbca-hsspi ff801000.spi: spi driver using polling mode
Nov 14 03:06:12 kernel: Assigning idx[3] for dummy0
Nov 14 03:06:12 kernel: Assigning idx[4] for ifb0
Nov 14 03:06:12 kernel: Assigning idx[5] for ifb1
Nov 14 03:06:12 kernel: Assigning idx[6] for imq0
Nov 14 03:06:12 kernel: Assigning idx[7] for imq1
Nov 14 03:06:12 kernel: Assigning idx[8] for imq2
Nov 14 03:06:12 kernel: IMQ driver loaded successfully. (numdevs = 3, numqueues = 1, imq_dev_accurate_stats = 1)
Nov 14 03:06:12 kernel: 	Hooking IMQ after NAT on PREROUTING.
Nov 14 03:06:12 kernel: 	Hooking IMQ before NAT on POSTROUTING.
Nov 14 03:06:12 kernel: PPP generic driver version 2.4.2
Nov 14 03:06:12 kernel: PPP BSD Compression module registered
Nov 14 03:06:12 kernel: PPP Deflate Compression module registered
Nov 14 03:06:12 kernel: PPP MPPE Compression module registered
Nov 14 03:06:12 kernel: NET: Registered protocol family 24
Nov 14 03:06:12 kernel: PPTP driver version 0.8.5
Nov 14 03:06:12 kernel: i2c /dev entries driver
Nov 14 03:06:12 kernel: sdhci: Secure Digital Host Controller Interface driver
Nov 14 03:06:12 kernel: sdhci: Copyright(c) Pierre Ossman
Nov 14 03:06:12 kernel: sdhci-pltfm: SDHCI platform and OF driver helper
Nov 14 03:06:12 kernel: pinctrl-bcmbca ff800554.pinctrl: pin PIN40 already requested by ff803000.led_ctrl:sw_parallel_led_14; cannot claim for ff810000.sdhci
Nov 14 03:06:12 kernel: pinctrl-bcmbca ff800554.pinctrl: pin-40 (ff810000.sdhci) status -22
Nov 14 03:06:12 kernel: pinctrl-bcmbca ff800554.pinctrl: could not request pin 40 (PIN40) from group BCMBCA_PINCTRL_GROUP_040  on device pinctrl-bcmbca
Nov 14 03:06:12 kernel: sdhci-bcm63xx ff810000.sdhci: Error applying setting, reverse things back
Nov 14 03:06:12 kernel: sdhci-bcm63xx: probe of ff810000.sdhci failed with error -22
Nov 14 03:06:12 kernel: hidraw: raw HID events driver (C) Jiri Kosina
Nov 14 03:06:12 kernel: GACT probability NOT on
Nov 14 03:06:12 kernel: Mirror/redirect action on
Nov 14 03:06:12 kernel: Simple TC action Loaded
Nov 14 03:06:12 kernel: u32 classifier
Nov 14 03:06:12 kernel:     Performance counters on
Nov 14 03:06:12 kernel:     input device check on
Nov 14 03:06:12 kernel:     Actions configured
Nov 14 03:06:12 kernel: xt_time: kernel timezone is -0000
Nov 14 03:06:12 kernel: gre: GRE over IPv4 demultiplexor driver
Nov 14 03:06:12 kernel: ip_gre: GRE over IPv4 tunneling driver
Nov 14 03:06:12 kernel: Assigning idx[9] for gre0
Nov 14 03:06:12 kernel: Assigning idx[10] for gretap0
Nov 14 03:06:12 kernel: Assigning idx[11] for erspan0
Nov 14 03:06:12 kernel: IPv4 over IPsec tunneling driver
Nov 14 03:06:12 kernel: Assigning idx[12] for ip_vti0
Nov 14 03:06:12 kernel: NET: Registered protocol family 10
Nov 14 03:06:12 kernel: Segment Routing with IPv6
Nov 14 03:06:12 kernel: Assigning idx[13] for ip6_vti0
Nov 14 03:06:12 kernel: sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
Nov 14 03:06:12 kernel: Assigning idx[14] for sit0
Nov 14 03:06:12 kernel: Assigning idx[15] for ip6tnl0
Nov 14 03:06:12 kernel: ip6_gre: GRE over IPv6 tunneling driver
Nov 14 03:06:12 kernel: Assigning idx[16] for ip6gre0
Nov 14 03:06:12 kernel: NET: Registered protocol family 17
Nov 14 03:06:12 kernel: NET: Registered protocol family 15
Nov 14 03:06:12 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Nov 14 03:06:12 kernel: l2tp_core: L2TP core driver, V2.0
Nov 14 03:06:12 kernel: l2tp_ppp: PPPoL2TP kernel driver, V2.0
Nov 14 03:06:12 kernel: 8021q: 802.1Q VLAN Support v1.8
Nov 14 03:06:12 kernel: sctp: Hash tables configured (bind 256/256)
Nov 14 03:06:12 kernel: brcmboard registered
Nov 14 03:06:12 kernel: brcmboard: brcm_board_init entry
Nov 14 03:06:12 kernel: BOOT REASON 0x24
Nov 14 03:06:12 kernel: RESET STATUS 0x20000000
Nov 14 03:06:12 kernel: Optical detection module loaded.
Nov 14 03:06:12 kernel: Broadcom GPS GPIO driver
Nov 14 03:06:12 kernel: bcm_memc 80040e28.memory_controller: matched the memory controller to brcm,bcm-memc
Nov 14 03:06:12 kernel: ioremapped reg phyctl_idle_pad_ctl <0x80060200 0x4> to ffffff8008195200
Nov 14 03:06:12 kernel: ioremapped reg phyctl_idle_pad_en0 <0x80060204 0x4> to ffffff800819d204
Nov 14 03:06:12 kernel: ioremapped reg phyctl_idle_pad_en1 <0x80060208 0x4> to ffffff80081a5208
Nov 14 03:06:12 kernel: ioremapped reg phybl0_idle_pad_ctl <0x8006071c 0x4> to ffffff80081ad71c
Nov 14 03:06:12 kernel: ioremapped reg phybl1_idle_pad_ctl <0x8006091c 0x4> to ffffff80081b591c
Nov 14 03:06:12 kernel: ioremapped reg phybl0_clock_idle <0x8006073c 0x4> to ffffff80081bd73c
Nov 14 03:06:12 kernel: ioremapped reg phybl1_clock_idle <0x8006093c 0x4> to ffffff80081c593c
Nov 14 03:06:12 kernel: ioremapped reg auto_self_refresh <0x8004000c 0x4> to ffffff80081cd00c
Nov 14 03:06:12 kernel: ioremapped reg glb_gcfg <0x80040008 0x4> to ffffff80081d5008
Nov 14 03:06:12 kernel: bcm_memc_get_of_memcfg: of memcfg=0x161635
Nov 14 03:06:12 kernel: bcm_memc_get_spd_mhz: memcfg=0x161635 spd_mhz=1600
Nov 14 03:06:12 kernel: bcm-ubus-dcm 83000080.ubus_dcm_sys: Broadcom BCA UBUS DCM Driver
Nov 14 03:06:12 kernel: bcm-ubus-dcm 83000080.ubus_dcm_sys: ubus dcm clk resource [mem 0x83000080-0x830000ff flags 0x200]
Nov 14 03:06:12 kernel: bcm-ubus-dcm 83000080.ubus_dcm_sys: map to virt addr 0xffffff80081dd080
Nov 14 03:06:12 kernel: Bridge Broadcom hooks registered
Nov 14 03:06:12 kernel: ebt_blog registered
Nov 14 03:06:12 kernel: ebt_ftos registered
Nov 14 03:06:12 kernel: ebt_qos_map registered
Nov 14 03:06:12 kernel: ebt_time registered
Nov 14 03:06:12 kernel: ebt_vtag registered
Nov 14 03:06:12 kernel: ebt_wmm_mark registered
Nov 14 03:06:12 kernel: ebt_reject registered
Nov 14 03:06:12 kernel: brcm-xport 837f0000.xport: registered
Nov 14 03:06:12 kernel: brcm-unimac 828a8000.unimac: registered
Nov 14 03:06:12 kernel: brcm-mdio 837ffd00.mdiosf2: registered
Nov 14 03:06:12 kernel: brcm,eth-phy-top 837ff000.ethphytop: registered
Nov 14 03:06:12 kernel: brcm-serdes1 837ff500.serdes: registered
Nov 14 03:06:12 kernel: swblks 837ff000.swblks: registered
Nov 14 03:06:12 kernel: brcm-ephyled 837ff1ac.ephyled: registered
Nov 14 03:06:12 kernel: brcm-mpcs 828c4000.mpcs: registered
Nov 14 03:06:12 kernel: Loading compiled-in X.509 certificates
Nov 14 03:06:12 kernel: ubi0: attaching mtd2
Nov 14 03:06:12 kernel: ubi0: scanning is finished
Nov 14 03:06:12 kernel: ubi0: attached mtd2 (name "image", size 253 MiB)
Nov 14 03:06:12 kernel: ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
Nov 14 03:06:12 kernel: ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
Nov 14 03:06:12 kernel: ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
Nov 14 03:06:12 kernel: ubi0: good PEBs: 2023, bad PEBs: 1, corrupted PEBs: 0
Nov 14 03:06:12 kernel: ubi0: user volume: 9, internal volumes: 1, max. volumes count: 128
Nov 14 03:06:12 kernel: ubi0: max/mean erase counter: 4215/2179, WL threshold: 4096, image sequence number: 533286310
Nov 14 03:06:12 kernel: ubi0: available PEBs: 124, total reserved PEBs: 1899, PEBs reserved for bad PEB handling: 39
Nov 14 03:06:12 kernel: ubi0: background thread "ubi_bgt0d" started, PID 119
Nov 14 03:06:12 kernel: block ubiblock0_4: created from ubi0:4(rootfs1)
Nov 14 03:06:12 kernel: Registered phy device: EGPHY:0x2
Nov 14 03:06:12 kernel: Registered phy device: EXT3:0x9
Nov 14 03:06:12 kernel: gpiod_direction_output: invalid GPIO (errorpointer)
Nov 14 03:06:12 kernel: Registered phy device: 10GAE:0x7
Nov 14 03:06:12 kernel: Registered phy device: EXT3:0x15
Nov 14 03:06:12 kernel: Registered phy device: 10GAE:0x8
Nov 14 03:06:12 kernel: VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
Nov 14 03:06:12 kernel: devtmpfs: mounted
Nov 14 03:06:12 kernel: Freeing unused kernel memory: 1280K
Nov 14 03:06:12 kernel: Checked W+X mappings: passed, no W+X pages found
Nov 14 03:06:12 kernel: Run /sbin/init as init process
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): background thread "ubifs_bgt0_10" started, PID 129
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): UBIFS: mounted UBI device 0, volume 10, name "data"
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): FS size: 19808256 bytes (18 MiB, 156 LEBs), journal size 1015809 bytes (0 MiB, 8 LEBs)
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): reserved for root: 935592 bytes (913 KiB)
Nov 14 03:06:12 kernel: UBIFS (ubi0:10): media format: w5/r0 (latest is w5/r0), UUID 40A144CA-8385-4F5A-B7B5-2B94D1C03DAD, small LPT model
Nov 14 03:06:12 kernel: Initializing WLCSM Module
Nov 14 03:06:12 kernel: WLCSM Module loaded successfully 
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): background thread "ubifs_bgt0_11" started, PID 241
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): UBIFS: mounted UBI device 0, volume 11, name "defaults"
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): FS size: 7237632 bytes (6 MiB, 57 LEBs), journal size 1015809 bytes (0 MiB, 6 LEBs)
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): reserved for root: 341850 bytes (333 KiB)
Nov 14 03:06:12 kernel: UBIFS (ubi0:11): media format: w5/r0 (latest is w5/r0), UUID 0E3B3FCF-8A2F-49E1-A570-9AF1F14AB464, small LPT model
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): background thread "ubifs_bgt0_13" started, PID 272
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): UBIFS: mounted UBI device 0, volume 13, name "jffs2"
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): FS size: 51171328 bytes (48 MiB, 403 LEBs), journal size 2539520 bytes (2 MiB, 20 LEBs)
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): reserved for root: 2416947 bytes (2360 KiB)
Nov 14 03:06:12 kernel: UBIFS (ubi0:13): media format: w5/r0 (latest is w5/r0), UUID 97C887DD-2990-4E65-824E-406B39458BE6, small LPT model
Nov 14 03:06:12 kernel: BCMLIBS loaded...
Nov 14 03:06:12 kernel: bcm_mpm: module license 'Proprietary' taints kernel.
Nov 14 03:06:12 kernel: Disabling lock debugging due to kernel taint
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom MPM Driver Initializing^[[0m
Nov 14 03:06:12 kernel: ebuf_size is adjusted to 1024 based on possible buffer sizes
Nov 14 03:06:12 kernel: MPM: virt_base = 0xffffffc06d000000, phys_base = 0x6d000000, total_mem_size = 268435456
Nov 14 03:06:12 kernel: MPM: ebuf_size = 2048, ebuf_total = 131072/262144
Nov 14 03:06:12 kernel: Pool[0]: alloc 1 EBUFs (2048 bytes)
Nov 14 03:06:12 kernel: Pool[1]: alloc 2 EBUFs (4096 bytes)
Nov 14 03:06:12 kernel: Pool[2]: alloc 4 EBUFs (8192 bytes)
Nov 14 03:06:12 kernel: Pool[3]: alloc 8 EBUFs (16384 bytes)
Nov 14 03:06:12 kernel: MPM Pool Numbers: SKB = 0, Data = 3, DQM = 0
Nov 14 03:06:12 kernel: MPM Registers are mapped to 0xffffff800c0b0000 (Phys@0x80020000)
Nov 14 03:06:12 kernel: MPM Total Commands = 41/64
Nov 14 03:06:12 kernel: MPM: ebuf_size 3, mpm_size_log2_kb 7
Nov 14 03:06:12 kernel: MPM Enabled
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom HW Memory Pool Manager (MPM) Char Driver v0.1 Registered <342>^[[0m
Nov 14 03:06:12 kernel: Broadcom BPM Module Char Driver v0.1 Registered<304>^[[0m
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: ^[[0;34m[NTC bpm] bpm_pool_manager_init: num_objs_per_slab:0 init_num_buf:5785
Nov 14 03:06:12 kernel: ^[[0m
Nov 14 03:06:12 kernel: ^[[0;34m[NTC bpm] bpm_init_buf_pool: buf_top_idx:5785^[[0m
Nov 14 03:06:12 kernel: ^[[0;34m[NTC bpm] bpm_init_buf_pool: num_bpm_slabs:0^[[0m
Nov 14 03:06:12 kernel: ^[[0;34m[NTC bpm] bpm_init_skb_pool: skbs pool inited total 5785^[[0m
Nov 14 03:06:12 kernel: Broadcom 802.1Q VLAN Interface, v0.1
Nov 14 03:06:12 kernel: Scratch pad is not initialized.
Nov 14 03:06:12 kernel: rdpa_get_init_system_dt_params: emac_map=e2 ext_sw_pid=30 usxgmiim_cnt=0
Nov 14 03:06:12 kernel: mpm_alloc_ring_alloc: Host 0xffffffc062c00000 (0xffffffc062c00000), Phys 0x62c00000 (0x62c00000), Size 128 (192) bytes
Nov 14 03:06:12 kernel: mpm_alloc_ring_alloc: alloc_ring 0, buf_mode FKB (0), buf_type 0
Nov 14 03:06:12 kernel: mpm_free_ring_alloc: Host 0xffffffc062c01000 (0xffffffc062c01000), Phys 0x62c01000 (0x62c01000), Size 128 (192) bytes
Nov 14 03:06:12 kernel: mpm_free_ring_alloc: free_ring 0
Nov 14 03:06:12 kernel: ++++Runner sg_desc_pool and sg_header_pool created successfully !!!!!!!!!!!!!!!!
Nov 14 03:06:12 kernel: SG descriptor Num_of_entries 4096, sz_of_entry 64, mem_size 262144, addr 0xffffffc057380000
Nov 14 03:06:12 kernel: SG header pool Num_of_entries 4096, sz_of_entry 128, mem_size 524288, addr 0xffffffc056980000
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 26 with 24576 packets descriptor=0xffffff8000fc9ca0, size_of_entry 8
Nov 14 03:06:12 kernel: Done initializing Ring 26 Base=0xffffffc057300000 num of entries= 24576 RDD Base=57300000 descriptor=0xffffff8000fc9ca0
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 30 with 24576 packets descriptor=0xffffff8000fc9ee0, size_of_entry 8
Nov 14 03:06:12 kernel: Done initializing Ring 30 Base=0xffffffc057340000 num of entries= 24576 RDD Base=57340000 descriptor=0xffffff8000fc9ee0
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 25 with 16384 packets descriptor=0xffffff8000fc9c10, size_of_entry 8
Nov 14 03:06:12 kernel: Done initializing Ring 25 Base=0xffffffc057200000 num of entries= 16384 RDD Base=57200000 descriptor=0xffffff8000fc9c10
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 24 with 4096 packets descriptor=0xffffff8000fc9b80, size_of_entry 8
Nov 14 03:06:12 kernel: Done initializing Ring 24 Base=0xffffffc05e720000 num of entries= 4096 RDD Base=5e720000 descriptor=0xffffff8000fc9b80
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 27 with 2048 packets descriptor=0xffffff8000fc9d30, size_of_entry 16
Nov 14 03:06:12 kernel: Done initializing Ring 27 Base=0xffffffc05e730000 num of entries= 2048 RDD Base=5e730000 descriptor=0xffffff8000fc9d30
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 28 with 2048 packets descriptor=0xffffff8000fc9dc0, size_of_entry 16
Nov 14 03:06:12 kernel: Done initializing Ring 28 Base=0xffffffc056900000 num of entries= 2048 RDD Base=56900000 descriptor=0xffffff8000fc9dc0
Nov 14 03:06:12 kernel: Creating CPU ring for queue number 29 with 2048 packets descriptor=0xffffff8000fc9e50, size_of_entry 16
Nov 14 03:06:12 kernel: Done initializing Ring 29 Base=0xffffffc056910000 num of entries= 2048 RDD Base=56910000 descriptor=0xffffff8000fc9e50
Nov 14 03:06:12 kernel: Enforcer is ready
Nov 14 03:06:12 kernel: Broadcom BP3 Driver - Platform: TELCO, BPA: v0, BLOB: v1, License Folder: "/rom/etc/licenses", Chip Name: 4916, OUI: E89C25, Release Tag: 5.04L.04p2
Nov 14 03:06:12 kernel: ^[[0;33;41m[ERROR bp3] traverse_dir_read_files_iteratively,159: Cannot open /etc/licenses directory^[[0m
Nov 14 03:06:12 kernel: ^[[0;33;41m[ERROR bp3] BP3_SEC_LicenseLoad,626: Failed to load default development license^[[0m
Nov 14 03:06:12 kernel: ^[[0;33;41m[ERROR bp3] traverse_dir_read_files_iteratively,159: Cannot open /rom/etc/licenses directory^[[0m
Nov 14 03:06:12 kernel: ^[[0;33;41m[ERROR bp3] BP3_SEC_LicenseLoad,631: Failed to load licenses from storage^[[0m
Nov 14 03:06:12 kernel: BP3 status - provisioned
Nov 14 03:06:12 kernel: Broadcom Ingress QoS Module  Char Driver v1.0 Registered<243>^[[0m
Nov 14 03:06:12 kernel: Broadcom Ingress QoS v1.0 initialized
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom Packet Flow Cache ^[[0m
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_UCAST_FLOW_ENTRIES<16384>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_MCAST_GROUPS<128>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_MCAST_CLIENTS_PER_GROUP<64>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_MCAST_CLIENTS<1024>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_UNKNOWN_UCAST_GROUPS<16>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_UNKNOWN_UCAST_CLIENTS_PER_GROUP<16>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_UNKNOWN_UCAST_CLIENTS<256>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_FDB_ENTRIES<1024>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_HOST_DEV_ENTRIES<64>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_HOST_MAC_ENTRIES<32>
Nov 14 03:06:12 kernel: FCACHE_CONFIG_MAX_FLOW_ENTRIES<17536>
Nov 14 03:06:12 kernel: npe_max_entries<17536>
Nov 14 03:06:12 kernel: Bind blog_notify_evt_enqueue_fn[<ffffff800115f080>]
Nov 14 03:06:12 kernel: fc_evt task created successfully
Nov 14 03:06:12 kernel: max_ent = 17536 intvl_msec = 10000 num_slices = 2000 num_ent = 9 period_msec = 5 
Nov 14 03:06:12 kernel: NBUFF v1.0 Initialized
Nov 14 03:06:12 kernel: fcache: max_groups<128> mcast_max_clients_per_group<64> mcast_max_clients<1024>
Nov 14 03:06:12 kernel: fcache: mcast_max_ent<1152>
Nov 14 03:06:12 kernel: fcache: unknown_ucast_max_groups<16> unknown_ucast_max_clients_per_group<16> unknown_ucast_max_clients<256>
Nov 14 03:06:12 kernel: fcache: unknown_ucast_group_max_ent<272>
Nov 14 03:06:12 kernel: fcache: ucast_max_ent<16384>
Nov 14 03:06:12 kernel: fcache: max_ent<17536>
Nov 14 03:06:12 kernel: group_type_mcast.group_bitmap_pool_p<ffffffc056675600>
Nov 14 03:06:12 kernel: group_type_unknown_ucast.group_bitmap_pool_p<ffffffc056675e80>
Nov 14 03:06:12 kernel: ^[[0;36;44mTotal # of labels = 78^[[0m
Nov 14 03:06:12 kernel: ^[[0;36;44mInitialized fcache state^[[0m
Nov 14 03:06:12 kernel: 	Pkt HW acceleration is disabled/unavailable.
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom Packet Flow Cache  Char Driver v4.0 Registered<302>^[[0m
Nov 14 03:06:12 kernel: fc_timer_task created successfully
Nov 14 03:06:12 kernel: 	Pkt HW acceleration is disabled/unavailable.
Nov 14 03:06:12 kernel: Created Proc FS /procfs/fcache
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom Packet Flow Cache registered with netdev chain^[[0m
Nov 14 03:06:12 kernel: ^[[0;36;44mBroadcom Packet Flow Cache learning via BLOG enabled.^[[0m
Nov 14 03:06:12 kernel: ^[[0;35m[FHW]  pktDbgLvl[0xffffff8001185808]=0^[[0m
Nov 14 03:06:12 kernel: ^[[0;34m[FHW]  fhw_construct: ^[[0m
Nov 14 03:06:12 kernel: ^[[0;36;44mInitialized Fcache HW accelerator layer state^[[0m
Nov 14 03:06:12 kernel: flwStatsThread created. numFlwsPerPoll 584 maxFlwIdx 17535
Nov 14 03:06:12 kernel: ^[[0;36;44mFcache Pathstats created^[[0m
Nov 14 03:06:12 kernel: ^[[0;36;44mConstructed Broadcom Packet Flow Cache v4.0^[[0m
Nov 14 03:06:12 kernel: Broadcom Command List Driver v1.0
Nov 14 03:06:12 kernel: bcm_tcp_module_load_notify: ***No valid HTOA license. Do not enable GDX for local tcp acceleration***
Nov 14 03:06:12 kernel: ^[[0;31mgdx_skb_offset_check: field head offset src 504 binary 480^[[0m
Nov 14 03:06:12 kernel: ^[[0;31mgdx_init: gdx_priv_init failure^[[0m
Nov 14 03:06:12 kernel: bcm_tcp_module_load_notify: ***No valid HTOA license. Do not enable GDX for local tcp acceleration***
Nov 14 03:06:12 kernel: bcmenet DT
Nov 14 03:06:12 kernel: Registered mac device: UNIMAC:0x1
Nov 14 03:06:12 kernel: Registered mac device: XPORT:0x5
Nov 14 03:06:12 kernel: Registered mac device: XPORT:0x6
Nov 14 03:06:12 kernel: Registered mac device: XPORT:0x7
Nov 14 03:06:12 kernel: Adjusted QGPHY: qphy_ctrl=0x0004101a ext_pwr_down=0xd
Nov 14 03:06:12 kernel: ^[[0;30;102mProbing Copper PHYs located at bus:^[[0m
Nov 14 03:06:12 kernel:     Detected Copper PHY at address  1 with PHY ID 0x3590.0x50e0: Not Defined in DT.
Nov 14 03:06:12 kernel:     Detected Copper PHY at address  2 with PHY ID 0x3590.0x50e0: EGPHY
Nov 14 03:06:12 kernel:     Detected Copper PHY at address  3 with PHY ID 0x3590.0x50e0: Not Defined in DT.
Nov 14 03:06:12 kernel:     Detected Copper PHY at address  4 with PHY ID 0x3590.0x50e0: Not Defined in DT.
Nov 14 03:06:12 kernel:    PHY defined in DT at address  7 PHY Type: 14 is not detected!!
Nov 14 03:06:12 kernel:    PHY defined in DT at address  8 PHY Type: 14 is not detected!!
Nov 14 03:06:12 kernel:     Detected Copper PHY at address  9 with PHY ID 0x3590.0x50e1: XPHY4916_X :
Nov 14 03:06:12 kernel:     Detected Copper PHY at address 21 with PHY ID 0x3590.0x5081: 84891L   B0:
Nov 14 03:06:12 kernel: Detecting PHYs...
Nov 14 03:06:12 kernel: 84891L   B0 3590:5081 --> 0x15 
Nov 14 03:06:12 kernel: XPHY4916_X  3590:50e1 --> 0x9 
Nov 14 03:06:12 kernel: Loading firmware into detected PHYs: map=0x200000 count=1
Nov 14 03:06:12 kernel:     PHY Addresses at  21, PHY Names:  84891L   B0, Firmware Name: blackfin_b0
Nov 14 03:06:12 kernel: Halt the PHYs processors operation
Nov 14 03:06:12 kernel: Registers: devid:01, ctrl:a817, ram_addr:00000000
Nov 14 03:06:12 kernel:            addr_low:a819, addr_high:a81a, data_low:a81b, data_high:a81c
Nov 14 03:06:12 kernel: Upload the firmware into the on-chip memory: file=/rom/etc/fw/blackfin_b0_firmware.bin size=294708
Nov 14 03:06:12 kernel: 10%^[[1A
Nov 14 03:06:12 kernel: 20%^[[1A
Nov 14 03:06:12 kernel: 30%^[[1A
Nov 14 03:06:12 kernel: 40%^[[1A
Nov 14 03:06:12 kernel: 50%^[[1A
Nov 14 03:06:12 kernel: 60%^[[1A
Nov 14 03:06:12 kernel: 70%^[[1A
Nov 14 03:06:12 kernel: 80%^[[1A
Nov 14 03:06:12 kernel: 90%^[[1A
Nov 14 03:06:12 kernel: 100%^[[1A
Nov 14 03:06:12 kernel: Reset the processors to start execution of the code in the on-chip memory
Nov 14 03:06:12 kernel: Verify that the processors are running: OK
Nov 14 03:06:12 kernel: Verify that the firmware has been loaded with good CRC: OK
Nov 14 03:06:12 kernel: Firmware loading completed successfully, version: (2.3.3)
Nov 14 03:06:12 kernel: Loading firmware into detected PHYs: map=0x200 count=1
Nov 14 03:06:12 kernel:     PHY Addresses at  9, PHY Names:  XPHY4916_X , Firmware Name: xphy
Nov 14 03:06:12 kernel: Halt the PHYs processors operation
Nov 14 03:06:12 kernel: Registers: devid:01, ctrl:a817, ram_addr:00000000
Nov 14 03:06:12 kernel:            addr_low:a819, addr_high:a81a, data_low:a81b, data_high:a81c
Nov 14 03:06:12 kernel: Upload the firmware into the on-chip memory: file=/rom/etc/fw/xphy_firmware.bin size=179516
Nov 14 03:06:12 kernel: 10%^[[1A
Nov 14 03:06:12 kernel: 20%^[[1A
Nov 14 03:06:12 kernel: 30%^[[1A
Nov 14 03:06:12 kernel: 40%^[[1A
Nov 14 03:06:12 kernel: 50%^[[1A
Nov 14 03:06:12 kernel: 60%^[[1A
Nov 14 03:06:12 kernel: 70%^[[1A
Nov 14 03:06:12 kernel: 80%^[[1A
Nov 14 03:06:12 kernel: 90%^[[1A
Nov 14 03:06:12 kernel: 100%^[[1A
Nov 14 03:06:12 kernel: Reset the processors to start execution of the code in the on-chip memory
Nov 14 03:06:12 kernel: Verify that the processors are running: OK
Nov 14 03:06:12 kernel: Verify that the firmware has been loaded with good CRC: OK
Nov 14 03:06:12 kernel: Firmware loading completed successfully, version: (0.0.12)
Nov 14 03:06:12 kernel: Missing Host_Traffic_Offload_Assist HTOA license, disable HW_GSO and switch to SW_GSO
Nov 14 03:06:12 kernel: Assigning idx[17] for bcmsw
Nov 14 03:06:12 kernel: BCMENET: Enabling Software GSO for bcmsw
Nov 14 03:06:12 kernel: Assigning idx[18] for eth2
Nov 14 03:06:12 kernel: BCMENET: Enabling Software GSO for eth2
Nov 14 03:06:12 kernel: Assigning idx[19] for eth0
Nov 14 03:06:12 kernel: BCMENET: Enabling Software GSO for eth0
Nov 14 03:06:12 kernel: Initialize XPHY at 9 LED registers.
Nov 14 03:06:12 kernel: Assigning idx[20] for eth1
Nov 14 03:06:12 kernel: BCMENET: Enabling Software GSO for eth1
Nov 14 03:06:12 kernel: ^[[0;30;102m=== Start of 10G Active Ethernet Initialization for core 0 port 0 ===^[[0m
Nov 14 03:06:12 kernel: --- Step 0 powerup/reset sequence of core #0 at address 7
Nov 14 03:06:12 kernel: Toggle Serdes Core #0 PMD and uC reset.
Nov 14 03:06:12 kernel: INFO MerlinSupport::merlin_core_init(): END. Core #0 with PRTAD = 7, ln_offset_stap = 0
Nov 14 03:06:12 kernel: MerlinSupport::merlin16_serdes_init(): Step 6. Micro code load and verify 
Nov 14 03:06:12 kernel: MerlinSupport::merlin_load_firmware(): ret = 0 
Nov 14 03:06:12 kernel: MerlinSupport::merline_speed_set_core(): Step 7 Config Speed to 2
Nov 14 03:06:12 kernel: No option found for: "-d ML_C_VCO_10P3125", added default value 0 in index 4
Nov 14 03:06:12 kernel: --- Step 8 PLL/PMD setup configuration for speed 10000, mode 2.
Nov 14 03:06:12 kernel: MerlinSupport::merline_speed_set_core(): PMD Setup 50MHz, 10.3125GHz VCO programming 
Nov 14 03:06:12 kernel: MerlinSupport::merlin_wait_uc_active():    wait 50us comclks for micro to be up...
Nov 14 03:06:12 kernel: MerlinSupport::merlin_wait_uc_active():  Checking uc_active passed ...
Nov 14 03:06:12 kernel: MerlinSupport::merlin_wait_uc_active():  micro is ready for command ...
Nov 14 03:06:12 kernel: MerlinSupport::merline_speed_set_core(): Step 9. Configure Core level regsiter 
Nov 14 03:06:12 kernel: MerlinSupport::merline_speed_set_core(): Step 10. Set core_congif_from_pcs 
Nov 14 03:06:12 kernel: No option found for: "-d ML_C_VCO_12P5", added default value 0 in index 5
Nov 14 03:06:12 kernel: MerlinSupport::merline_speed_set_core(): RAM variable vco_rate is 19 
Nov 14 03:06:12 kernel: MerlinSupport::merlin_cfg_core_ram_var():  program core_config_word 0x26 to ram address 0x20000200 ```

@Martinski4GitHub
Copy link
Collaborator Author

Now, if the reboot after the F/W update is not occurring at all... That would be a separate problem to figure out.

It has to be occuring, we have a reboot in the script, the router logs indicate a reboot and my network goes down, the RGB lights flash of a firmware upgrade in progress and it comes back online with the new firmware version flashed.

How can it possibly not be rebooting?

Yes, that's my initial thought as well. The reboot must be happening as it's also coded in the script.
The same thing can be said of the Lock file still remaining after the reboot. How can that possibly happen? It's not physically possible.

Your theory was that the Lock file is essentially surviving a reboot even though it's stored in a temporary virtual filesystem (i.e. created in volatile RAM) and after the reboot, the file is still there not allowing another instance of the script to execute.

I still hold that my theory was lock file related and this is lock file related hehehehahaha :P

This would mean that there is more than one instance of the script being launched, one right after the other.
That can happen only if something else is executing 2 or more instances. That would be a new problem or a new symptom of the same problem.

@ExtremeFiretop
Copy link
Owner

I got the solution; you pointed me there!

@Martinski4GitHub
Copy link
Collaborator Author

MERLINAU UPGRADE STARTING:

..

DISCONNECT FROM SSH LOGS:

...

UPGRADE SIGNAL STARTING:

...

MORE STOPPING LOGS:

...

DONE

STARTING:
...

I don't know what I'm supposed to look for in all these logs. Is there a specific issue?

@ExtremeFiretop
Copy link
Owner

MERLINAU UPGRADE STARTING:
..
DISCONNECT FROM SSH LOGS:
...
UPGRADE SIGNAL STARTING:
...
MORE STOPPING LOGS:
...
DONE
STARTING:
...

I don't know what I'm supposed to look for in all these logs. Is there a specific issue?

No issue; just confirming that it did infact reboot as per the logs. :)
I said we had logs showing a reboot, but I noticed the previous examples didn't actually show a shutdown complete.

@Martinski4GitHub
Copy link
Collaborator Author

MERLINAU UPGRADE STARTING:
..
DISCONNECT FROM SSH LOGS:
...
UPGRADE SIGNAL STARTING:
...
MORE STOPPING LOGS:
...
DONE
STARTING:
...

I don't know what I'm supposed to look for in all these logs. Is there a specific issue?

No issue; just confirming that it did infact reboot as per the logs. :) I said we had logs showing a reboot, but I noticed the previous examples didn't actually show a shutdown complete.

Ah OK. I noticed your router doesn't show the "default initial time" during the reboot process (usually May 4 2018 or May 5 2018).
Is that a new thing for the latest routers with 3006 F/W?

@ExtremeFiretop
Copy link
Owner

MERLINAU UPGRADE STARTING:
..
DISCONNECT FROM SSH LOGS:
...
UPGRADE SIGNAL STARTING:
...
MORE STOPPING LOGS:
...
DONE
STARTING:
...

I don't know what I'm supposed to look for in all these logs. Is there a specific issue?

No issue; just confirming that it did infact reboot as per the logs. :) I said we had logs showing a reboot, but I noticed the previous examples didn't actually show a shutdown complete.

Ah OK. I noticed your router doesn't show the "default initial time" during the reboot process (usually May 4 2018 or May 5 2018). Is that a new thing for the latest routers with 3006 F/W?

I thought that was due to the router date keeper addon tbh.
It's why I continue to install it for when I review the syslogs.

You'll notice in the logs above the following line:

Nov 14 03:06:12 amtm routerdate: Preserving router date before reboot (2024-11-14 08:06:12) UTC time.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants